Issue #7976 has been updated by Jahfer Husain.


I recently found this behaviour while attempting to build a gem that outputs the full call graph for our Rails application. 

Using TracePoint, we can capture all calls/returns with the object the method is invoked upon, but finding the actual site of the invocation is a daunting task. My gem is a C-extension, and after much experimentation, the only reliable way to get the correct caller  is through using `caller_locations`, which computes the full backtrace from the VM and is a significant slowdown when compared to using `rb_tracearg_path`.

As a point of comparison, we can run 63k tests (parallelized) while invoking `rb_tracearg_path` in roughly 10 minutes, whereas using `caller_locations` takes about 1.5 hours to complete.

Regardless of how the file paths are computed, their accuracy is significant for the performance of our gem because we are able to use a blacklist to ignore logging all gem method invocations as well as Rails core or other infrastructural pieces that we do not need to trace. 

I also attempted to use `:line` events as David Rodrguez suggested above, but on returns the value is always pointing to the deepest part of the stack most recently touched. The method does work well for calls though (albeit expensive to trace every line event).

You can see the different results (along with my personal expectation of what _should_ be returned) in this gist: https://gist.github.com/jahfer/092e44df6f15298bae3cf47056301708#gistcomment-2015893

----------------------------------------
Bug #7976: TracePoint call is at call point, not call site
https://bugs.ruby-lang.org/issues/7976#change-63308

* Author: Ryan Davis
* Status: Feedback
* Priority: Normal
* Assignee: Koichi Sasada
* Target version: 2.2.0
* ruby -v: 2.0
* Backport: 
----------------------------------------
Using TracePoint to make a new tracer utility I'm finding it very difficult to actually trace where the origin is for type :call. Instead, I get the destination. This is not the case for :c_call or :b_call as they trace at the origin, not destination.

Reproduction attached. Notice how it outputs ":call     wtf.rb:08 :x" where line 8 is the definition of x, not the call of x, yet the subsequent backtrace lists line 21 which is the original origin for the call to x.

---Files--------------------------------
tp_test.rb (1.21 KB)


-- 
https://bugs.ruby-lang.org/

Unsubscribe: <mailto:ruby-core-request / ruby-lang.org?subject=unsubscribe>
<http://lists.ruby-lang.org/cgi-bin/mailman/options/ruby-core>