ruby-changes:70005
From: Alan <ko1@a...>
Date: Thu, 2 Dec 2021 07:42:48 +0900 (JST)
Subject: [ruby-changes:70005] 9121e57a5f (master): Rework tracing for blocks running as methods
https://git.ruby-lang.org/ruby.git/commit/?id=9121e57a5f From 9121e57a5f50bc91bae48b3b91edb283bf96cb6b Mon Sep 17 00:00:00 2001 From: Alan Wu <XrXr@u...> Date: Tue, 13 Jul 2021 19:01:09 -0400 Subject: Rework tracing for blocks running as methods The main impetus for this change is to fix [Bug #13392]. Previously, we fired the "return" TracePoint event after popping the stack frame for the block running as method (BMETHOD). This gave undesirable source location outputs as the return event normally fires right before the frame going away. The iseq for each block can run both as a block and as a method. To accommodate that, this commit makes vm_trace() fire call/return events for instructions that have b_call/b_return events attached when the iseq is running as a BMETHOD. The logic for rewriting to "trace_*" instruction is tweaked so that when the user listens to call/return events, instructions with b_call/b_return become trace variants. To continue to provide the return value for non-local returns done using the "return" or "break" keyword inside BMETHODs, the stack unwinding code is tweaked. b_return events now provide the same return value as return events for these non-local cases. A pre-existing test deemed not providing a return value for these b_return events as a limitation. This commit removes the checks for call/return TracePoint events that happen when calling into BMETHODs when no TracePoints are active. Technically, migrating just the return event is enough to fix the bug, but migrating both call and return removes our reliance on `VM_FRAME_FLAG_FINISH` and re-entering the interpreter when the caller is already in the interpreter. --- iseq.c | 25 ++++++++- iseq.h | 2 +- test/ruby/test_settracefunc.rb | 122 +++++++++++++++++++++++++++++++++++++++-- vm.c | 73 +++++++++++------------- vm_insnhelper.c | 35 ++++++++++-- vm_trace.c | 13 +++-- 6 files changed, 210 insertions(+), 60 deletions(-) diff --git a/iseq.c b/iseq.c index f0117d94ce6..e42525cb9fa 100644 --- a/iseq.c +++ b/iseq.c @@ -3310,6 +3310,23 @@ rb_iseq_trace_flag_cleared(const rb_iseq_t *iseq, size_t pos) https://github.com/ruby/ruby/blob/trunk/iseq.c#L3310 encoded_iseq_trace_instrument(&iseq_encoded[pos], 0, false); } +// We need to fire call events on instructions with b_call events if the block +// is running as a method. So, if we are listening for call events, then +// instructions that have b_call events need to become trace variants. +// Use this function when making decisions about recompiling to trace variants. +static inline rb_event_flag_t +add_bmethod_events(rb_event_flag_t events) +{ + if (events & RUBY_EVENT_CALL) { + events |= RUBY_EVENT_B_CALL; + } + if (events & RUBY_EVENT_RETURN) { + events |= RUBY_EVENT_B_RETURN; + } + return events; +} + +// Note, to support call/return events for bmethods, turnon_event can have more events than tpval. static int iseq_add_local_tracepoint(const rb_iseq_t *iseq, rb_event_flag_t turnon_events, VALUE tpval, unsigned int target_line) { @@ -3365,9 +3382,12 @@ iseq_add_local_tracepoint_i(const rb_iseq_t *iseq, void *p) https://github.com/ruby/ruby/blob/trunk/iseq.c#L3382 } int -rb_iseq_add_local_tracepoint_recursively(const rb_iseq_t *iseq, rb_event_flag_t turnon_events, VALUE tpval, unsigned int target_line) +rb_iseq_add_local_tracepoint_recursively(const rb_iseq_t *iseq, rb_event_flag_t turnon_events, VALUE tpval, unsigned int target_line, bool target_bmethod) { struct trace_set_local_events_struct data; + if (target_bmethod) { + turnon_events = add_bmethod_events(turnon_events); + } data.turnon_events = turnon_events; data.tpval = tpval; data.target_line = target_line; @@ -3399,6 +3419,7 @@ iseq_remove_local_tracepoint(const rb_iseq_t *iseq, VALUE tpval) https://github.com/ruby/ruby/blob/trunk/iseq.c#L3419 ((rb_iseq_t *)iseq)->aux.exec.local_hooks = NULL; } + local_events = add_bmethod_events(local_events); for (pc = 0; pc<body->iseq_size;) { rb_event_flag_t pc_events = rb_iseq_event_flags(iseq, pc); pc += encoded_iseq_trace_instrument(&iseq_encoded[pc], pc_events & (local_events | iseq->aux.exec.global_trace_events), false); @@ -3449,7 +3470,7 @@ rb_iseq_trace_set(const rb_iseq_t *iseq, rb_event_flag_t turnon_events) https://github.com/ruby/ruby/blob/trunk/iseq.c#L3470 rb_event_flag_t enabled_events; rb_event_flag_t local_events = iseq->aux.exec.local_hooks ? iseq->aux.exec.local_hooks->events : 0; ((rb_iseq_t *)iseq)->aux.exec.global_trace_events = turnon_events; - enabled_events = turnon_events | local_events; + enabled_events = add_bmethod_events(turnon_events | local_events); for (pc=0; pc<body->iseq_size;) { rb_event_flag_t pc_events = rb_iseq_event_flags(iseq, pc); diff --git a/iseq.h b/iseq.h index eb46367379a..cc68b8d3f8a 100644 --- a/iseq.h +++ b/iseq.h @@ -160,7 +160,7 @@ const rb_iseq_t *rb_iseq_ibf_load(VALUE str); https://github.com/ruby/ruby/blob/trunk/iseq.h#L160 const rb_iseq_t *rb_iseq_ibf_load_bytes(const char *cstr, size_t); VALUE rb_iseq_ibf_load_extra_data(VALUE str); void rb_iseq_init_trace(rb_iseq_t *iseq); -int rb_iseq_add_local_tracepoint_recursively(const rb_iseq_t *iseq, rb_event_flag_t turnon_events, VALUE tpval, unsigned int target_line); +int rb_iseq_add_local_tracepoint_recursively(const rb_iseq_t *iseq, rb_event_flag_t turnon_events, VALUE tpval, unsigned int target_line, bool target_bmethod); int rb_iseq_remove_local_tracepoint_recursively(const rb_iseq_t *iseq, VALUE tpval); const rb_iseq_t *rb_iseq_load_iseq(VALUE fname); diff --git a/test/ruby/test_settracefunc.rb b/test/ruby/test_settracefunc.rb index 4a374265313..d737c84af5e 100644 --- a/test/ruby/test_settracefunc.rb +++ b/test/ruby/test_settracefunc.rb @@ -393,7 +393,7 @@ class TestSetTraceFunc < Test::Unit::TestCase https://github.com/ruby/ruby/blob/trunk/test/ruby/test_settracefunc.rb#L393 [["c-return", 3, :set_trace_func, Kernel], ["line", 6, __method__, self.class], ["call", 1, :foobar, FooBar], - ["return", 6, :foobar, FooBar], + ["return", 1, :foobar, FooBar], ["line", 7, __method__, self.class], ["c-call", 7, :set_trace_func, Kernel]].each{|e| assert_equal(e, events.shift) @@ -1951,7 +1951,7 @@ CODE https://github.com/ruby/ruby/blob/trunk/test/ruby/test_settracefunc.rb#L1951 end define_method(:f_break_defined) do - return :f_break_defined + break :f_break_defined end define_method(:f_raise_defined) do @@ -1972,27 +1972,44 @@ CODE https://github.com/ruby/ruby/blob/trunk/test/ruby/test_settracefunc.rb#L1972 tp_return_value(:f_last_defined), '[Bug #13369]' - assert_equal [[:b_return, :f_return_defined, nil], # current limitation + assert_equal [[:b_return, :f_return_defined, :f_return_defined], [:return, :f_return_defined, :f_return_defined]], tp_return_value(:f_return_defined), '[Bug #13369]' - assert_equal [[:b_return, :f_break_defined, nil], + assert_equal [[:b_return, :f_break_defined, :f_break_defined], [:return, :f_break_defined, :f_break_defined]], tp_return_value(:f_break_defined), '[Bug #13369]' - assert_equal [[:b_return, :f_raise_defined, nil], + assert_equal [[:b_return, :f_raise_defined, f_raise_defined], [:return, :f_raise_defined, f_raise_defined]], tp_return_value(:f_raise_defined), '[Bug #13369]' - assert_equal [[:b_return, :f_break_in_rescue_defined, nil], + assert_equal [[:b_return, :f_break_in_rescue_defined, f_break_in_rescue_defined], [:return, :f_break_in_rescue_defined, f_break_in_rescue_defined]], tp_return_value(:f_break_in_rescue_defined), '[Bug #13369]' end + define_method(:just_yield) do |&block| + block.call + end + + define_method(:unwind_multiple_bmethods) do + just_yield { return :unwind_multiple_bmethods } + end + + def test_non_local_return_across_multiple_define_methods + assert_equal [[:b_return, :unwind_multiple_bmethods, nil], + [:b_return, :just_yield, nil], + [:return, :just_yield, nil], + [:b_return, :unwind_multiple_bmethods, :unwind_multiple_bmethods], + [:return, :unwind_multiple_bmethods, :unwind_multiple_bmethods]], + tp_return_value(:unwind_multiple_bmethods) + end + def f_iter yield end @@ -2403,6 +2420,99 @@ CODE https://github.com/ruby/ruby/blob/trunk/test/ruby/test_settracefunc.rb#L2420 assert_equal Array.new(2){th}, events end + def test_return_bmethod_location + bug13392 = "[ruby-core:80515] incorrect bmethod return location" + actual = nil + obj = Object.new + expected = __LINE__ + 1 + obj.define_singleton_method(:t){} + tp = TracePoint.new(:return) do + next unless target_thread? + actual = tp.lineno + end + tp.enable {obj.t} + assert_equal(expected, actual, bug13392) + end + + def test_b_tracepoints_going_away + # test that call and return TracePoints continue to work + # when b_call and b_return TracePoints stop + events = [] + record_events = ->(tp) do + next unless target_thread? + events << [tp.event, tp.method_id] + end + + call_ret_tp = TracePoint.new(:call, :return, &record_events) + block_call_ret_tp = TracePoint.new(:b_call, :b_return, &record_events) + + obj = Object.new + obj.define_singleton_method(:foo) {} # a bmethod + + foo = obj.method(:foo) + call_ret_tp.enable(target: foo) do + block_call_ret_tp.enable(target: foo) do + obj.foo + end + obj (... truncated) -- ML: ruby-changes@q... Info: http://www.atdot.net/~ko1/quickml/