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/ (branch spike/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 -pg profile (30k req/endpoint through the fiber server) split self-time as ~55% GC/alloc, ~25% other runtime, ~7–10% user codeflat 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.rb found 48 positions where roundhouse says concrete and Spinel widened (e.g. ArticleRow#body: Stringuntyped). The culprit is a Hash[String, untyped] read (row["body"]) — and per upstream docs/HASH-NULLABLE.md a str_poly_hash read is a poly slot by design, while docs/RBS-EXTRACT.md notes 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 the body/title asymmetry (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:

surfacewhat it givesreplaces
SPINEL_ALLOC_REPORT=1|pathper-type counts + # bytes (alloc;<Type> <n>)the sp_gc_* frame-name heuristic
SPINEL_ALLOC_SITES=1callsite 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.jsonthe 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 buildspinel 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):

commitdateresult
c4591143 (earliest with bin/spinel)2026-06-18segfault
c92caf1d2026-07-05undefined method 'length' for nil
0610c59d / e67010de2026-07-26same
e896643e (master)2026-08-09same

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:

  • --debug produces 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_hash compiles to sp_str_hash, which clashes with the runtime's sp_str_hash(const char*) in lib/sp_str.h — the generated C does not compile. roundhouse escapes this only because its version is Tep.str_hashsp_Tep_str_hash.
  • The build log also shows an -Wincompatible-pointer-types warning in ViewHelpers.stylesheet_link_tag (sp_SymPolyHash * initialising an sp_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.patch3 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:

  1. Nil strictness (corpus, one line). Reads of Tep.str_hash-backed hashes assumed a miss answers "". request.rb:50 had even documented the old behaviour in a comment. Fixed by giving the hash an explicit default (h.default = "") in Tep.str_hash — correct under CRuby too, so both runtimes now agree instead of the tree depending on a compiler quirk.
  2. Sym/Str poly-hash confusion (compiler). The -Wincompatible-pointer-types warning at view_helpers.rb:211 was a real miscompile, not noise. render_attrs unified to sp_StrPolyHash * while stylesheet_link_tag passed a Symbol-keyed hash, so sp_StrPolyHash_get dereferenced a Symbol as a char * → SIGSEGV at address 0xbe. Worked around by making the keys uniformly strings; the compile warning disappears with it. --profile is what caught this — an unstripped -O2 -g build gave gdb a complete Ruby-level backtrace on the first try.
  3. Hash#to_h on a non-Symbol-keyed boxed hash (compiler) — raises where CRuby returns self. Dropped the redundant calls. Minimal repro in tools/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 the render_attrs miscompile, 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 / request392199
bytes / request54.2 KB9.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/reqtypesite
73Stringsp_str_concat
45Hash(String,String)sp_StrStrHash_new
26Stringsp_re_gsub_str_str_hash
20Hash(Symbol)sp_SymPolyHash_new
16Stringsp_Main_s_dispatchmain.rb:301
6Stringsp_Articles_s_indexindex.rb:26
6scansp_ViewHelpers_s_render_attrsview_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.rb ships a stricter one (sp_gc_* only) and reports 23.9% on the same gmon.out and the same binary. The 14-point spread is entirely whether sp_str_sweep_gen and sp_StrStrHash_scan count 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 Array number 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_escape is a regex gsub. It is called 780 000 times over 30 000 requests (26/req), and it accounts for the 26 String allocations/req at sp_re_gsub_str_str_hash plus 7.5% of profile self-time in sp_re_frame_push/sp_re_frame_pop. A non-regex html_escape is 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:

upstreambugrepro
#3972Hash#to_h raises on a non-Symbol-keyed boxed hashminimal — repro/toh3.rb
#3973def str_hash collides with the runtime's sp_str_hash; generated C won't compileminimal — repro/collide.rb
#3974uncaught exception prints no file:line and no backtrace, even under --debugminimal — repro/nilraise.rb
#3975Sym/Str poly-hash unification miscompile → SIGSEGVcorpus 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 perf half cannot be validated here. gx10 runs perf_event_paranoid=4, so perf record is unavailable — the same constraint that motivated the original RFC. Upstream already validated the --profileperf 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:

  1. A static slowness predictor — the degrade scan. --emit-rbs / --emit-types mark every slot where inference fell to the boxed untyped / 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 doctor already counts these.

  2. A dynamic hot-spot mapper — the #line map. A --debug / -g build carries #line directives (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.