Perf analysis
August 16, 2026 · View on GitHub
Proposal → now partly measured. The correctness tools answer "does the compiled binary match CRuby?" This is the performance counterpart: should you compile this at all, and where is the compiled code paying for dynamism. It reuses substrate we already built — no new compiler research. The tools below are spiked in
tools/perf/(branchspike/perf-tools); the Measured results section records what they found on a real Rails app.
Measured results (roundhouse Rails blog) — see tools/perf/README.md
The spike ran the full battery against roundhouse's Rails blog (one app AOT-compiled to spinel, ~1.4–1.9× over CRuby). The headline overturned the starting hypothesis, which is the useful part:
- The ceiling is allocation, not boxing. ⚠ This split is inferred, not
measured — see the owed rerun below. A live
-pgprofile (30k req/endpoint through the fiber server) split self-time as ~55% GC/alloc, ~25% other runtime, ~7–10% user code — flat across endpoints, matching the flat ~20ms p99. The "hot ∧ poly" share (user self-time on the boxed slow path) is ≈0%: the residual poly is real but cold. So on Rails-shaped glue, AOT already won the dispatch battle; what's left is object-allocation pressure (#new+ view helpers), which AOT doesn't remove. This decomposition answers spinel-dev#7's tier question: reaching the crystal tier here is an allocation-strategy problem (escape analysis / scalar replacement / pooling), not a type-inference one. - Granularity matters and cuts both ways. Signature (
--emit-rbs) vs position (--emit-types) untyped: 22.8% of methods vs 3.19% of positions. The signature scan under-counts on a clean-boundary/boxed-body method (churn) and over-counts at app scale — both are why an unweighted scan can't predict speedup, and why the profile-weighted score is load-bearing. - Residual boxing = inferencer disagreement, and some of it is by design.
rbs-disagree.rbfound 48 positions where roundhouse says concrete and Spinel widened (e.g.ArticleRow#body: String→untyped). The culprit is aHash[String, untyped]read (row["body"]) — and per upstreamdocs/HASH-NULLABLE.mdastr_poly_hashread is apolyslot by design, whiledocs/RBS-EXTRACT.mdnotes seeds are advisory and the analyzer widens on observed contradiction. So that widen is the analyzer working as documented (roundhouse-optimistic vs spinel-conservative), not a clear bug — the open question is thebody/titleasymmetry (why one widens and the structurally-identical other survives).
The rerun that is owed (#1336)
The ~55% above is a heuristic twice over: gprof apportions self-time up
caller paths (not sampled stacks), and the GC share is then recovered by matching
frame names against sp_gc_* in tools/perf/spinel-flamegraph.rb. That was the
best available at the time; it no longer is.
matz/spinel#1336 — our RFC for a
native sampling profiler — was answered with something better than what we asked
for. The sampler was deferred (it would have profiled the -O0 debug build; see
docs/05 §G), and two deterministic surfaces
shipped instead:
| surface | what it gives | replaces |
|---|---|---|
SPINEL_ALLOC_REPORT=1|path | per-type counts + # bytes (alloc;<Type> <n>) | the sp_gc_* frame-name heuristic |
SPINEL_ALLOC_SITES=1 | callsite as outer folded frame (alloc;<site>;<Type> <n>) | gprof's caller-path apportioning |
spinel app.rb --profile -o app | -O2 -g -fno-omit-frame-pointer, unstripped, + app.symbols.json | the hand-rolled -pg -g -O2 build in the tools |
The commitment made upstream (comment):
rerun this same roundhouse workload with the counters on and post
heuristic vs. measured — i.e. how far off the 55–72% frame-name numbers
were. That comparison is the deliverable, and it is calibration for any future
sampled work, so the corpus must not change: a rerun on tep/toy/optcarrot
measures a different program and answers a different question. The base project
is roundhouse's spinel target, unpacked at
/srv/data/scratch/roundhouse/spinel (the same tree that produced the numbers
above — make build → spinel main.rb --rbs sig -o build/blog, make seed for
tmp/blog.sqlite3).
Status as of 2026-08-05: blocked on a roundhouse runtime regression
Step zero is done. ~/sites/spinel was updated from the stale detached
f6d5eefe (2026-06-03) to 8e07a52d (2026-08-05) and rebuilt — the C compiler
builds in ~32 s on gx10, and all three surfaces are verified working on aarch64:
$ spinel w.rb --profile -o wprof # writes wprof + wprof.symbols.json
$ SPINEL_ALLOC_REPORT=1 SPINEL_ALLOC_SITES=1 ./wprof
alloc;/lib/aarch64-linux-gnu/libc.so.6(+0x284c4) [0xee25ca3884c4];String 1000
alloc;./wprof(+0x2d0c) [0xbc240eeb2d0c];Widget 1000
alloc;./wprof(+0x27d0) [0xbc240eeb27d0];Array(Object) 1
# bytes ./wprof(+0x2d0c) [0xbc240eeb2d0c];Widget 16000
Two things that audit confirmed for the consumer work: with SPINEL_ALLOC_SITES=1
the # bytes lines also carry the site (so a reader must strip # lines after
the site is in play, not before), and the one-frame limit upstream documented bites
immediately — the String allocations attribute to libc, not to user code.
The rerun itself is blocked. roundhouse compiles under the current C compiler (5.8 s, vs. minutes for the Ruby compiler) but the binary dies on the first HTTP request:
$ BLOG_DB=tmp/blog.sqlite3 PORT=8731 ./build/blog
undefined method 'length' for nil (NoMethodError)
The Jun-4 binary (built by the pre-rewrite Ruby compiler, kept at
/srv/data/scratch/roundhouse/spinel/build/blog) still serves /articles →
200/6354 B and /articles/1.json → 200/320 B from the same tree and DB.
Root cause — and it is not a compiler bug
The bisect does not name a culprit commit, because there is no good commit to
bisect to. Probing the C-compiler era (harness at
/srv/data/scratch/spinel-bisect-test.sh, ~5–30 s per step):
| commit | date | result |
|---|---|---|
c4591143 (earliest with bin/spinel) | 2026-06-18 | segfault |
c92caf1d | 2026-07-05 | undefined method 'length' for nil |
0610c59d / e67010de | 2026-07-26 | same |
e896643e (master) | 2026-08-09 | same |
roundhouse has never run under the rewritten compiler. The only working binary predates it.
Instrumenting the request path localises the current failure exactly — it is
runtime/tep/parser.rb:66:
cookie_blob = req.req_headers["cookie"]
if cookie_blob.length > 0 # <- NoMethodError: nil.length
req_headers is a Tep.str_hash — a typed Hash[String,String] built via the
{"" => ""} + delete trick. A request with no Cookie: header misses, and the
miss now answers nil. The vendored Tep runtime was written against spinel's
older typed-hash behaviour, where a miss answered the type's zero value ("") —
which is why the Jun-4 binary serves fine: that line executes on every
cookie-less request.
Current spinel is CRuby-correct here, confirmed with a minimal repro (both
answer nil on miss):
h = ({"" => ""}); h.delete(""); h["host"] = "example.com"
h["cookie"] # CRuby: nil spinel e896643e: nil (old spinel: "")
So this is not a regression to file against the compiler — it is upstream's
Hash-nullable / CRuby-semantics work (docs/HASH-NULLABLE.md, since removed;
the July Hash default/default_proc series) landing correctly, and roundhouse's
vendored runtime relying on the previous non-Ruby behaviour. The fix belongs in
the corpus, not the compiler.
And it is not a single site. Sending a Cookie: header gets past line 66 and
fails further downstream with undefined method 'downcase' for nil — the header
loop and cookie parse both succeed, so at least one more nil-on-miss assumption
sits in the router/dispatch layer.
Two incidental findings worth their own reports:
--debugproduces no backtrace for these raises, so the native-backtrace path (#1300, ours) does not cover them.- User method names can collide with runtime symbols. A top-level
def str_hashcompiles tosp_str_hash, which clashes with the runtime'ssp_str_hash(const char*)inlib/sp_str.h— the generated C does not compile. roundhouse escapes this only because its version isTep.str_hash→sp_Tep_str_hash. - The build log also shows an
-Wincompatible-pointer-typeswarning inViewHelpers.stylesheet_link_tag(sp_SymPolyHash *initialising ansp_StrPolyHash *) — a real emitted-code type confusion, unrelated to this failure but on the HTML layout path.
Corpus repaired — 2026-08-16
Done, verified against master d61264ea. The patch is
tools/perf/corpus/roundhouse-modern-spinel.patch
— 3 files, 66 lines; the harness that produced the numbers below is beside it
(load.rb, measure.sh, analyze.rb, alloc-reports/, repro/).
Validation: output is byte-identical to the Jun-4 binary on /articles
(6354 B), /articles/1.json (320 B), and /articles/1 (4930 B). The repair is
semantics-preserving, so the rerun measures the same program #7 measured.
Three distinct problems, and only two of them are compiler bugs:
- Nil strictness (corpus, one line). Reads of
Tep.str_hash-backed hashes assumed a miss answers"".request.rb:50had even documented the old behaviour in a comment. Fixed by giving the hash an explicit default (h.default = "") inTep.str_hash— correct under CRuby too, so both runtimes now agree instead of the tree depending on a compiler quirk. - Sym/Str poly-hash confusion (compiler). The
-Wincompatible-pointer-typeswarning atview_helpers.rb:211was a real miscompile, not noise.render_attrsunified tosp_StrPolyHash *whilestylesheet_link_tagpassed a Symbol-keyed hash, sosp_StrPolyHash_getdereferenced a Symbol as achar *→ SIGSEGV at address0xbe. Worked around by making the keys uniformly strings; the compile warning disappears with it.--profileis what caught this — an unstripped-O2 -gbuild gave gdb a complete Ruby-level backtrace on the first try. Hash#to_hon a non-Symbol-keyed boxed hash (compiler) — raises where CRuby returns self. Dropped the redundant calls. Minimal repro intools/perf/corpus/repro/toh3.rb.
Retracted. An earlier revision of this section claimed a fourth bug — that
Hash.new("")/h.default = ""segfaults on these hashes. It does not. That segfault was problem 2 in disguise: at the time it was observed the corpus still carried therender_attrsmiscompile, so every build crashed regardless of the hash change. Both default forms work on current master, which is why the corpus fix above is one line rather than ten call-site guards. Recorded here because "the obvious fix crashes" would have been a costly thing to leave on the record — and because it is the reason to re-verify a bug against a current build before filing it.
The rerun — measured, at last
30 000 requests/endpoint through the fiber server, SPINEL_ALLOC_REPORT on, with
a 0-request baseline subtracted so startup cannot masquerade as churn:
/articles (HTML) | /articles/1.json | |
|---|---|---|
| allocations / request | 392 | 199 |
| bytes / request | 54.2 KB | 9.0 KB |
| startup share of the above | ~0 (baseline is ~100 allocations total) | ~0 |
Top allocators per request (/articles), and where they come from
(SPINEL_ALLOC_SITES=1, symbolised against the --profile build):
| allocations/req | type | site |
|---|---|---|
| 73 | String | sp_str_concat |
| 45 | Hash(String,String) | sp_StrStrHash_new |
| 26 | String | sp_re_gsub_str_str_hash |
| 20 | Hash(Symbol) | sp_SymPolyHash_new |
| 16 | String | sp_Main_s_dispatch → main.rb:301 |
| 6 | String | sp_Articles_s_index → index.rb:26 |
| 6 | scan | sp_ViewHelpers_s_render_attrs → view_helpers.rb:351 |
Heuristic vs. measured — what the comparison actually shows. Re-running the
old frame-name method (-pg build, gprof, sp_gc_* matching) on this same build
gives GC/alloc 37.7%, other runtime 43.1%, user 19.2% — against #7's
originally-reported 55.6 / 24.8 / 10.0. That gap is not a clean measure of how
much the heuristic was lying: the compiler changed (Ruby → C, plus ~2 months of GC
work) and the load driver changed (a Ruby keep-alive driver here, wrk -c16
there), so the two numbers are not the same experiment.
The heuristic is even softer than that. The
37.7%above comes from a GC pattern that counts sweep/scan frames.tools/perf/spinel-flamegraph.rbships a stricter one (sp_gc_*only) and reports 23.9% on the samegmon.outand the same binary. The 14-point spread is entirely whethersp_str_sweep_genandsp_StrStrHash_scancount as collector work — and both readings are defensible. So "the GC share" was never a single number the frame-name method could produce; it was a number per regex. That is the sharpest available argument for the counters, which have no such knob, and it is why no honest calibration of the old 55% was ever going to be possible.
What the counters do settle, and what the heuristic could never have told us:
- The allocation is churn, not a live set. This is the exact check that
overturned upstream's optcarrot reading, where a big
Arraynumber turned out to be a startup LUT. Here the 0-request baseline is ~100 allocations total, so all 392/request is per-request garbage. #7's "allocation-bound" framing survives contact with a real measurement. - The attribution is now exact. Not "≈55% of self-time sits in frames whose
names start with
sp_gc_", but 392 counted allocations with types and sites. - A concrete lead the heuristic hid:
html_escapeis a regexgsub. It is called 780 000 times over 30 000 requests (26/req), and it accounts for the 26 String allocations/req atsp_re_gsub_str_str_hashplus 7.5% of profile self-time insp_re_frame_push/sp_re_frame_pop. A non-regexhtml_escapeis the single most obvious win on this corpus.
Honest limit: the counters measure allocation volume, not time. They
cannot by themselves produce a "% of runtime in GC" number, so they do not falsify
the 55% directly — they replace the question. The remaining way to close that loop
is perf record on a --profile build, still blocked here at
perf_event_paranoid=4.
Bugs reported upstream (the nil-strictness change is not among them — it is
correct behaviour). Each re-verified against master d61264ea before filing:
| upstream | bug | repro |
|---|---|---|
| #3972 | Hash#to_h raises on a non-Symbol-keyed boxed hash | minimal — repro/toh3.rb |
| #3973 | def str_hash collides with the runtime's sp_str_hash; generated C won't compile | minimal — repro/collide.rb |
| #3974 | uncaught exception prints no file:line and no backtrace, even under --debug | minimal — repro/nilraise.rb |
| #3975 | Sym/Str poly-hash unification miscompile → SIGSEGV | corpus only (no minimal repro; compile warning localises it) |
The rerun itself is posted at #1336 (comment).
Filing note: three of the four minimised cleanly; #4 resisted every reduction
attempt (plain two-caller, .merge + defaulted-opts, three-caller variants all
compile and run correctly), so it went upstream as a corpus repro with the gdb
backtrace and the compile-time warning rather than as a fabricated minimal case.
The remaining precondition:
- The
perfhalf cannot be validated here. gx10 runsperf_event_paranoid=4, soperf recordis unavailable — the same constraint that motivated the original RFC. Upstream already validated the--profile→perf record -g→ folded loop at paranoid 1, so this blocks only our re-validation, not the feature. It is not the "hardened CI host" case upstream set as the bar for reviving the sampler: paranoid 4 here is a sysctl default on DGX OS, changeable with root, not a locked image.
Note that the allocation-counter half — which is the half the #7 rerun actually
needs — requires no perf at all. It is a runtime env var on any build.
The premise (matz/spinel#282)
Spinel is not uniformly faster than CRuby. It compiles tight, monomorphic,
numerically-typed code to clean C and wins big; it loses on polymorphic,
dispatch-heavy, dynamic code — exactly the shape of #282's tree-walking
interpreter (every var reference walks a string-keyed hash + strcmp; every node
visit recurses through boxed poly dispatch with GC rooting). CRuby's YARV gets
interned-symbol envs, inline caches, and stack frames "for free"; an AOT tree
walker doesn't.
So the useful questions aren't "is AOT faster" (sometimes) but:
- CRuby project / gem author: "Would compiling with Spinel make me much faster, marginally faster, or slower?" — before investing in the port.
- Spinel project: "It's slower than I hoped. Which Ruby is slow, and why?"
The substrate already exists
The two halves of an answer are things the correctness tooling already produces:
-
A static slowness predictor — the degrade scan.
--emit-rbs/--emit-typesmark every slot where inference fell to the boxeduntyped/ poly slow path. That is the "where Spinel can't generate fast C" map. A high untyped/poly ratio (especially on hot, dispatch-shaped methods) predicts the #282 outcome; a low ratio over numeric code predicts a big win — without running anything.spinel doctoralready counts these. -
A dynamic hot-spot mapper — the
#linemap. A--debug/-gbuild carries#linedirectives (now upstream, #1292). That lets an off-the-shelf native profiler (perf,gprof,samply) attribute hot C samples back to Ruby source lines — the same map value-bisect uses for crash localization.
Overlay the two and you get the payoff sentence: "62% of runtime is in
parser.rb:120–155, which the degrade scan shows on the poly slow path
(node is untyped) — that's your cost, and that's why."
Proposed tools
spinel speedup-estimate <program|gem> (static, cheap)
Runs the degrade scan + a few structural heuristics (numeric vs string/hash vs dispatch-shaped; share of calls that resolve monomorphically; container churn) and emits a verdict + evidence:
likely MUCH faster — 96% of methods monomorphic-typed, numeric-dominant, no poly dispatch
marginal — mixed; hot path types cleanly but I/O-bound
likely SLOWER — 40% untyped/poly, string-keyed-hash dispatch dominates (cf. #282)
This is the "should I even try" gate for a CRuby gem author — and it's mostly a
re-presentation of --emit-types we already have.
spinel perf <program.rb> [-- args] (dynamic) — spiked as tools/perf/spinel-perf.rb
Compile -g, profile, symbolize hot frames back to Ruby via the #line map, and
annotate each hot line with its inferred type / degrade status — a flat profile
keyed by .rb:line, each tagged on the boxed slow path or not, plus a GC-vs-user
self-time split (the thing that surfaced the allocation ceiling above), so "what's
slow" and "why" land together. Note: perf is locked down on the gx10 box
(perf_event_paranoid=4), so the spike uses gprof (-pg); perf/samply
would sharpen the per-line resolution where permitted.
Superseded in part. The hand-rolled -pg -g -O2 build these tools do is now a
first-class compiler flavor — spinel app.rb --profile -o app emits the -O2
binary with frame pointers, symtab, and app.symbols.json in one invocation
(upstream docs/profiling.md). And the GC-vs-user split, the load-bearing output
here, no longer has to be recovered from frame names: SPINEL_ALLOC_REPORT counts
it. Teaching tools/perf/ those two formats is the open consumer work
(see the owed rerun).
Validating the predictor — done (two corpora)
- Spinel's own 57-benchmark suite (CRuby vs Spinel, startup subtracted): Spearman ρ = 0.62 (n=10) between the static degrade score and the measured compute speedup — the cheap scan meaningfully orders programs. Caveat: every Spinel benchmark is 0% untyped, so the numeric-share half carries it there.
- roundhouse Rails blog (the missing dispatch/alloc-heavy corpus): see Measured results above — the static degrade score correctly reads low (the poly is cold), and the real ceiling turned out to be GC/alloc, which the dynamic GC-split profile surfaces. The two corpora together cover the numeric and the glue ends; a poly-hot corpus (a real interpreter) is the remaining gap.
Why this fits
It's the same thesis as the correctness tools: expose what the compiler already knows. Inference tells you where dynamism survives into the binary; that's both a miscompile risk surface and a performance risk surface. One scan, two answers. #282 is the motivating case — the tool would have called that interpreter "likely slower" statically, before the 30× surprise.