Bug #13392: TracePoint return event location is incorrect for methods defined with define_method

• Status: Closed
• Assignee: -
• Target version: -
• ruby -v: ruby 2.4.1p111 (2017-03-22 revision 58053) [x86_64-linux]
• Backport: 2.2: UNKNOWN, 2.3: UNKNOWN, 2.4: UNKNOWN
• Tags: tracepoint

[areman01 (André Kullmann)]

Command

ruby tracepoint_bug.rb

Output

ruby-2.4.1-p111 (x86_64-linux)
tracepoint_bug_ext.rb:4 call to_s
tracepoint_bug_ext.rb:5 c_call to_s
tracepoint_bug_ext.rb:5 c_return to_s
racepoint_bug.rb:12 return to_s

Why the call event on to_s is in file tracepoint_bug_ext.rb and the return event in file tracepoint_bug.rb? I think it's a bug. In jruby, for example, the call and the return event are both fired in the tracepoint_bug_ext.rb file.

[jeremyevans0 (Jeremy Evans)]

• Subject changed from TracePoint doesn't work correct with monkey patches / aliased methods to TracePoint return event location is incorrect for methods defined with define_method

This isn't an issue specific to monkey patches or aliased methods. This is a general issue with the :return event handling of bmethods (methods defined using blocks instead of with def). The return event handling occurs after the related VM frame has been popped instead of before, which is why the return event for bmethods shows the caller location instead of the return location in the callee. I've submitted a pull request to fix this: https://github.com/ruby/ruby/pull/4588

[jeremyevans0 (Jeremy Evans)]

• Related to Bug #14817: TracePoint#parameters for bmethod's return event should return the same value as its Method#parameters added

[alanwu (Alan Wu)]

I implemented an alternative fix that is more complicated but allows for future optimizations here: https://github.com/ruby/ruby/pull/4637
Some relevant details about it are in Jeremy's GitHub PR.

[alanwu (Alan Wu)]

• Status changed from Open to Closed

Applied in changeset git|9121e57a5f50bc91bae48b3b91edb283bf96cb6b.

---

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.