ruby-changes:68877
From: Aaron <ko1@a...>
Date: Thu, 21 Oct 2021 08:15:00 +0900 (JST)
Subject: [ruby-changes:68877] 4faaa8e5dc (master): Collect statistics about binding allocations / local variable set
https://git.ruby-lang.org/ruby.git/commit/?id=4faaa8e5dc From 4faaa8e5dc28f31f71f3ed145e834b94cd9f84d5 Mon Sep 17 00:00:00 2001 From: Aaron Patterson <tenderlove@r...> Date: Wed, 7 Apr 2021 12:51:50 -0700 Subject: Collect statistics about binding allocations / local variable set This commit collects statistics about how many binding objects are allocated as well as the number of local variables set on bindings. Statistics are output along with other YJIT stats. Here is an example of the output: ``` ***YJIT: Printing runtime counters from yjit.rb*** Number of Bindings Allocated: 195 Number of locals modified through binding: 0 opt_send_without_block exit reasons: ivar_get_method 7515891 (40.4%) se_cc_klass_differ 3081330 (16.6%) iseq_argc_mismatch 1564578 ( 8.4%) se_receiver_not_heap 1557663 ( 8.4%) ic_empty 1407064 ( 7.6%) optimized_method 995823 ( 5.4%) iseq_not_simple 819413 ( 4.4%) alias_method 706972 ( 3.8%) bmethod 685253 ( 3.7%) callsite_not_simple 225983 ( 1.2%) kw_splat 25999 ( 0.1%) ivar_set_method 902 ( 0.0%) cfunc_toomany_args 394 ( 0.0%) refined_method 42 ( 0.0%) cfunc_ruby_array_varg 29 ( 0.0%) invalid_cme 4 ( 0.0%) leave exit reasons: se_finish_frame 4067107 (100.0%) se_interrupt 24 ( 0.0%) getinstancevariable exit reasons: undef 121177 (100.0%) idx_out_of_range 5 ( 0.0%) opt_aref exit reasons: (all relevant counters are zero) compiled_iseq_count: 3944 main_block_code_size: 1.1 MiB side_block_code_size: 0.6 MiB vm_insns_count: 1137268516 yjit_exec_insns_count: 414015644 ratio_in_yjit: 26.7% avg_len_in_yjit: 7.5 total_exit_count: 55491789 most frequent exit op: opt_send_without_block: 18587628 (33.5%) opt_getinlinecache: 11075822 (20.0%) send: 4949300 (8.9%) leave: 4067131 (7.3%) defined: 3975196 (7.2%) setinstancevariable: 3567315 (6.4%) invokesuper: 2982163 (5.4%) getblockparamproxy: 2168852 (3.9%) opt_nil_p: 2104524 (3.8%) opt_aref: 2013858 (3.6%) ``` Running RailsBench allocates 195 binding objects but doesn't set any local variables. --- proc.c | 8 ++++++++ yjit.h | 2 ++ yjit.rb | 3 +++ yjit_iface.c | 12 ++++++++++++ yjit_iface.h | 3 +++ 5 files changed, 28 insertions(+) diff --git a/proc.c b/proc.c index e09aeca223..99b522d95f 100644 --- a/proc.c +++ b/proc.c @@ -21,6 +21,7 @@ https://github.com/ruby/ruby/blob/trunk/proc.c#L21 #include "method.h" #include "iseq.h" #include "vm_core.h" +#include "yjit.h" #if !defined(__GNUC__) || __GNUC__ < 5 || defined(__MINGW32__) # define NO_CLOBBERED(v) (*(volatile VALUE *)&(v)) @@ -346,6 +347,9 @@ rb_binding_alloc(VALUE klass) https://github.com/ruby/ruby/blob/trunk/proc.c#L347 VALUE obj; rb_binding_t *bind; obj = TypedData_Make_Struct(klass, rb_binding_t, &ruby_binding_data_type, bind); +#if RUBY_DEBUG + rb_yjit_collect_binding_alloc(); +#endif return obj; } @@ -610,6 +614,10 @@ bind_local_variable_set(VALUE bindval, VALUE sym, VALUE val) https://github.com/ruby/ruby/blob/trunk/proc.c#L614 env = VM_ENV_ENVVAL_PTR(vm_block_ep(&bind->block)); } +#if RUBY_DEBUG + rb_yjit_collect_binding_set(); +#endif + RB_OBJ_WRITE(env, ptr, val); return val; diff --git a/yjit.h b/yjit.h index b72de1a16e..cfb25a529d 100644 --- a/yjit.h +++ b/yjit.h @@ -51,6 +51,8 @@ void rb_yjit_invalidate_all_method_lookup_assumptions(void); https://github.com/ruby/ruby/blob/trunk/yjit.h#L51 void rb_yjit_method_lookup_change(VALUE klass, ID mid); void rb_yjit_cme_invalidate(VALUE cme); void rb_yjit_collect_vm_usage_insn(int insn); +void rb_yjit_collect_binding_alloc(void); +void rb_yjit_collect_binding_set(void); void rb_yjit_compile_iseq(const rb_iseq_t *iseq, rb_execution_context_t *ec); void rb_yjit_init(struct rb_yjit_options *options); void rb_yjit_bop_redefined(VALUE klass, const rb_method_entry_t *me, enum ruby_basic_operators bop); diff --git a/yjit.rb b/yjit.rb index a05c2b2d24..1272e1747b 100644 --- a/yjit.rb +++ b/yjit.rb @@ -60,6 +60,9 @@ module YJIT https://github.com/ruby/ruby/blob/trunk/yjit.rb#L60 $stderr.puts("***YJIT: Printing runtime counters from yjit.rb***") + $stderr.puts "Number of Bindings Allocated: %d\n" % counters[:binding_allocation_count] + $stderr.puts "Number of locals modified through binding: %d\n" % counters[:local_variable_set_count] + print_counters(counters, prefix: 'oswb_', prompt: 'opt_send_without_block exit reasons: ') print_counters(counters, prefix: 'leave_', prompt: 'leave exit reasons: ') print_counters(counters, prefix: 'getivar_', prompt: 'getinstancevariable exit reasons:') diff --git a/yjit_iface.c b/yjit_iface.c index 4e931f4c8d..989f7f9a56 100644 --- a/yjit_iface.c +++ b/yjit_iface.c @@ -726,6 +726,18 @@ rb_yjit_collect_vm_usage_insn(int insn) https://github.com/ruby/ruby/blob/trunk/yjit_iface.c#L726 vm_insns_count++; } +void +rb_yjit_collect_binding_alloc(void) +{ + yjit_runtime_counters.binding_allocations++; +} + +void +rb_yjit_collect_binding_set(void) +{ + yjit_runtime_counters.binding_set++; +} + const VALUE * rb_yjit_count_side_exit_op(const VALUE *exit_pc) { diff --git a/yjit_iface.h b/yjit_iface.h index bc1f1a7ad6..6428906b28 100644 --- a/yjit_iface.h +++ b/yjit_iface.h @@ -58,6 +58,9 @@ YJIT_DECLARE_COUNTERS( https://github.com/ruby/ruby/blob/trunk/yjit_iface.h#L58 oaref_argc_not_one, oaref_arg_not_fixnum, + binding_allocations, + binding_set, + // Member with known name for iterating over counters last_member ) -- cgit v1.2.1 -- ML: ruby-changes@q... Info: http://www.atdot.net/~ko1/quickml/