ZJIT: Notes from profiling week #995

Activity

1. tenderworks commented on Jun 23, 2026

   

   tenderworks

   on Jun 23, 2026

   More actions

   Polymorphic attr_readers end up doing slow-path IV reads.

   For example this code:

   class A
     attr_reader :name
   
     def initialize
       @name = "a"
     end
   end
   
   class B
     attr_reader :name
   
     def initialize
       @name = "a"
     end
   end
   
   def get_name obj; obj.name; end
   
   objs = [A.new, B.new]
   n = 0
   3000.times { objs.each { |o| n += 1 if get_name(o) } }

   The HIR for the get_name method looks like this:

   Optimized HIR:
   fn get_name@test.rb:17:
   bb1():
     EntryPoint interpreter
     v1:BasicObject = LoadSelf
     v2:CPtr = LoadSP
     v3:BasicObject = LoadField v2, :obj@-0x20
     Jump bb3(v1, v3)
   bb2():
     EntryPoint JIT(0)
     v6:BasicObject = LoadArg :self@0
     v7:BasicObject = LoadArg :obj@1
     Jump bb3(v6, v7)
   bb3(v9:BasicObject, v10:BasicObject):
     v15:CBool = HasType v10, ObjectSubclass[class_exact:A]
     CondBranch v15, bb5(v9, v10, v10), bb6()
   bb5(v16:BasicObject, v17:BasicObject, v18:BasicObject):
     v20:ObjectSubclass[class_exact:A] = RefineType v18, ObjectSubclass[class_exact:A]
     PatchPoint NoSingletonClass(A@0x7f367294e6c0)
     PatchPoint MethodRedefined(A@0x7f367294e6c0, name@0xe51, cme:0x7f3672924e38)
     v46:BasicObject = GetIvar v20, :@name
     Jump bb4(v16, v17, v46)
   bb6():
     v24:CBool = HasType v10, ObjectSubclass[class_exact:B]
     CondBranch v24, bb7(v9, v10, v10), bb8()
   bb7(v25:BasicObject, v26:BasicObject, v27:BasicObject):
     v29:ObjectSubclass[class_exact:B] = RefineType v27, ObjectSubclass[class_exact:B]
     PatchPoint NoSingletonClass(B@0x7f367294e8a0)
     PatchPoint MethodRedefined(B@0x7f367294e8a0, name@0xe51, cme:0x7f3672924f50)
     v49:BasicObject = GetIvar v29, :@name
     Jump bb4(v25, v26, v49)
   bb8():
     v33:BasicObject = Send v10, :name # SendFallbackReason: SendWithoutBlock: polymorphic fallback
     Jump bb4(v9, v10, v33)
   bb4(v35:BasicObject, v36:BasicObject, v37:BasicObject):
     CheckInterrupts
     Return v37
   

   The call site is polymorphic (which is fine), but we end up with slow path GetIvar instructions.
2. XrXr commented on Jun 23, 2026

   

   XrXr

   on Jun 23, 2026

   Last edited by XrXr

   More actions

   I made a jig to trace fallbacks to get a clearer picture of where the fallbacks are at the ruby level and how much time they take: ruby/ruby@master...Shopify:ruby:perfetto-trace-fallbacks

   Details

   ZJIT: add --zjit-trace-fallbacks to trace JIT/interpreter execution Emit Perfetto duration slices for time spent in JIT code versus the interpreter, so a trace shows where a workload's time goes across the JIT/interpreter boundary. The codegen plants hooks at the boundary crossings:

   • the interpreter->JIT entry (gen_entry_point, interpreter entry only)
   • each send fallback to the interpreter (rb_vm_send and friends),
     bracketed by begin/end calls around the C call
   • the JIT exit trampoline (the common funnel for side exits)

   These call into stats.rs helpers that keep at most one execution span
   open at a time (depth <= 1), so slices never overlap: every transition
   ends the current span before beginning the next. Recording is limited to
   single-Ractor mode, where the GVL serializes JIT execution and tracer
   access is safe.

   Three things are deliberately not fully accounted for, and a trace
   should be read with them in mind:

   • The "interpreter" spans are really fallback spans. They are only
     opened at send-fallback call sites, so they measure interpreter time
     reached via a JIT fallback, not all interpreter execution. The slice
     name is kept constant ("interpreter") for easy filtering; the
     specific fallback kind (e.g. "invokesuper") rides along in the kind
     argument.

   • Interpreter time that never enters JIT code is unaccounted for. With
     no JIT entry there is no span to open, so top-level interpreter
     execution that never reaches a compiled method produces no slices at
     all.

   • jit->fallback->jit nesting leaves gaps. When a fallback's interpreter
     work itself calls a compiled method, that inner JIT entry ends the
     interpreter span and the inner exit ends the JIT span; the remaining
     interpreter time before control returns to the original fallback site
     is left with no open span. So a jit->fallback->jit sequence can have
     unaccounted-for portions.

   Co-Authored-By: Claude Opus 4.8 (1M context) noreply@anthropic.com

   Using the following query:

   WITH shared_sq_0 AS (
     SELECT *
     FROM thread_or_process_slice
   ),
   shared_sq_1014 AS (
     SELECT *
     FROM shared_sq_0
     WHERE name = 'interpreter'
   ),
   shared_sq_1015 AS (
     SELECT id AS id, ts AS ts, dur AS dur, name AS name, track_id AS track_id, track_name AS track_name, process_name AS process_name, upid AS upid, pid AS pid, thread_name AS thread_name, utid AS utid, tid AS tid, depth AS depth, parent_id AS parent_id, category AS category, arg_set_id AS arg_set_id, extract_arg(arg_set_id, 'rb_src_loc') AS rb_src_loc, extract_arg(arg_set_id, 'kind') AS kind
     FROM shared_sq_1014
   ),
   total_dur AS ( SELECT SUM(dur) as total_dur FROM shared_sq_1015 )
   SELECT kind, rb_src_loc, SUM(dur) as sum_dur, CAST(SUM(dur) AS FLOAT) / total_dur * 100 as percentage
     FROM shared_sq_1015 JOIN total_dur
     GROUP BY kind, rb_src_loc
     ORDER BY sum_dur DESC
     LIMIT 20

   I got:

   kind	rb_src_loc	sum_dur	percentage
   invokeblock	each@internal:array:222	3559903556	11.057846
   invokeblock	map@internal:array:240	1676811762	5.208547
   send	_read_attribute@/Users/alan/.g	1429947740	4.441733
   send_without_block	hash@/Users/alan/.gem/ruby/dev	1016660559	3.157972
   send_without_block	build_arel@/Users/alan/.gem/ru	370303559	1.150245
   send_without_block	visit@/Users/alan/.gem/ruby/de	347445947	1.079244
   send	mon_synchronize@/Users/alan/.r	333434204	1.035720
   send_without_block	attribute_aliases@/Users/alan/	294062384	0.913423
   send_without_block	to_sql_and_binds@/Users/alan/.	293645491	0.912128
   send_without_block	_reflections@/Users/alan/.gem/	286159398	0.888874
   send_without_block	for@/Users/alan/.gem/ruby/dev/	282288717	0.876851
   send_without_block	association@/Users/alan/.gem/r	279158587	0.867128
   send_without_block	new!@/Users/alan/.gem/ruby/dev	262693720	0.815985
   send_without_block	block in inspect@/Users/alan/.	260729278	0.809883
   send_without_block	block in handler_for@/Users/al	258343982	0.802473
   invokeblock	select@internal:array:266	250344457	0.777625
   send	_run@/Users/alan/.gem/ruby/dev	236843425	0.735688
   send_without_block	spawn@/Users/alan/.gem/ruby/de	219825515	0.682827
   send_without_block	method_missing@/Users/alan/.ge	219410725	0.681538
   send_without_block	block in initialize@/Users/ala	212540646	0.660198

   So, there is a few clear major contributors and a long tail. Tracing was done on 10 iterations of lobsters in ruby-bench
3. nirvdrum commented on Jun 24, 2026

   

   nirvdrum

   on Jun 24, 2026

   More actions

   When running with the inliner enabled I've observed the number of dynamic ivar reads jumps 69% and ivar writes 74%. There's no side-exit involved so Perfetto can't really help. Instrumenting a build and tracing lobsters, it looks like ActiveRecord and ActionView are the largest triggers. However, I've managed to demonstrate the problem with a far smaller example:

   class A
   def initialize = @v = 1
   def read = @v
   end
   
   class B
   def initialize = @v = 1
   def read = @v
   end
   
   objs = [A.new, B.new]
   
   1_000_000.times { |i| objs[i % 2].read }

   I applied ruby#17455 to get finer-grained detail on what the source of the dynamic ivar reads is. Running the example above, I see ~1 M dynamic ivar reads that are all no_profile cases. When I enable inlining (--zjit-inline-threshold=30), I see the dynamic ivar read count jump to 2 M (also all no_profile). So, there are two problems I wanted to dig into: 1) why are there so many no_profile cases, and 2) why does inlining cause that count to double?

   I think the problem is that a polymorphic method on a hot path can hit the compilation threshold before callees even start profiling. If I run the above with --zjit-num-profiles=15, both dynamic_getivar_count and the no_profile fallback cut in half. Running with --zjit-num-profiles=25, the dynamic_getivar_count goes to 0.

   The problem scales with the number of unique types we see at a call site, so adjusting --zjit-num-profiles isn't a viable solution to this problem. Rails has some hot paths, such as template rendering, where a dispatcher is going to see tons of unique types (e.g., the @output_buffer). The lobsters benchmark trips over this in a few places.

   Separately, there's a bug in inlining that will count the same no_profile read multiple times. E.g., in this case ZJIT stats show that there were 2 M dynamic ivar reads with inlining enabled and 1 M without inlining. But, that doesn't make sense because there are only 1 M ivar reads in total. The culprit is the optimize loop. Each pass through the loop will run optimize_getivar on the accumulated function. That runs RPO on the result of inlining and for any non-profiled GetIvar it'll push an IncrCounter for getivar_fallback_not_monomorphic. If we inline we're guaranteed to run through the optimize loop at least two times¹. Since there's no marker indicating a given instruction has already been accounted for, we just push a new IncrCounter. I suspect this is a problem in other areas as well.

   So, it turns out there's a problem with dynamic ivar accesses in lobsters irrespective of inlining. The huge jump in dynamic ivar access counts, however, isn't a major regression -- we're just counting events incorrectly.

   ¹ -- Not really guaranteed. Someone could set --zjit-inline-max-iterations to prevent more than one optimization pass, but that's not the default and not expected in typical use.

   👍React with 👍1Reacted by Max Bernstein
4. tekknolagi commented on Jun 24, 2026

   

   tekknolagi

   on Jun 24, 2026

   Author

   More actions

   @rwstauner I don't think you can compare dev build compile or runtimes. We do some extensive checking in dev builds

   👍React with 👍1Reacted by Randy Stauner
5. tekknolagi commented on Jun 24, 2026

   

   tekknolagi

   on Jun 24, 2026

   Author

   More actions

   @nirvdrum FYI I think we hit a problem in that code even without inlining, which is that we don't handle (polymorphic method x polymorphic IV) well