Given
def run
puts "Backtracie: " + Backtracie.caller_locations.first.label
puts "Ruby: " + caller_locations.first.label
end
def run2
1.times do
run
end
end
the output is
Backtracie: run2 Ruby: block in run2
this is because inside rb_profile_frames
the code goes
/* record frame info */
cme = rb_vm_frame_method_entry(cfp);
if (cme && cme->def->type == VM_METHOD_TYPE_ISEQ) {
buff[i] = (VALUE)cme;
}
else {
buff[i] = (VALUE)cfp->iseq;
}
and in this case the first branch is taken (we get the cme
, not the cfp→iseq
). I have no idea why.
When using the cfp→iseq
instead of the cme
, in many cases, the full_label
, classpath
, qualified_method_name
, singleton_method_p
and first_lineno
become less accurate.
Why "less accurate"? Consider the following slightly compacted diff taken with backtracie and either cme
or cfp→iseq usage
, using the interesting_backtrace_helper.rb
, looking at the output in the debug fields for the Backtracie::Location
instances:
--- cfp->iseq
+++ cme
@@ -6,16 +6,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello",
"hello",
- "ClassA#hello",
+ "hello",
18,
- "ClassA",
+ nil,
false,
"hello",
- "ClassA#hello"],
+ "hello"],
@@ -23,16 +23,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello",
"hello",
- "ModuleB::ClassB#hello",
+ "hello",
27,
- "ModuleB::ClassB",
+ nil,
false,
"hello",
- "ModuleB::ClassB#hello"],
+ "hello"],
@@ -40,16 +40,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello",
"hello",
- "ModuleC.hello",
+ "hello",
34,
- "ModuleC",
- true,
+ nil,
+ false,
"hello",
- "ModuleC.hello"],
+ "hello"],
@@ -57,16 +57,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello",
"hello",
- "ClassWithStaticMethod.hello",
+ "hello",
40,
- "ClassWithStaticMethod",
- true,
+ nil,
+ false,
"hello",
- "ClassWithStaticMethod.hello"],
+ "hello"],
@@ -74,16 +74,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello",
"hello",
- "ModuleD#hello",
+ "hello",
46,
- "ModuleD",
+ nil,
false,
"hello",
- "ModuleD#hello"],
+ "hello"],
@@ -125,16 +125,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello",
"hello",
- "#<ClassD:0x0000556485af28e8>.hello",
+ "hello",
63,
- "#<ClassD:0x0000556485af28e8>",
- true,
+ nil,
+ false,
"hello",
- "#<ClassD:0x0000556485af28e8>.hello"],
+ "hello"],
@@ -142,16 +142,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello",
"hello",
- "ClassE#hello",
+ "hello",
68,
- "ClassE",
+ nil,
false,
"hello",
- "ClassE#hello"],
+ "hello"],
@@ -176,16 +176,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello",
"hello",
- "#<Module:0x0000556485af2140>#hello",
+ "hello",
82,
- "#<Module:0x0000556485af2140>",
+ nil,
false,
"hello",
- "#<Module:0x0000556485af2140>#hello"],
+ "hello"],
@@ -193,16 +193,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello",
"hello",
- "ModuleE.hello",
+ "hello",
92,
- "ModuleE",
- true,
+ nil,
+ false,
"hello",
- "ModuleE.hello"],
+ "hello"],
@@ -210,33 +210,33 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"method_missing",
"method_missing",
- "ClassH#method_missing",
+ "method_missing",
98,
- "ClassH",
+ nil,
false,
"method_missing",
- "ClassH#method_missing"],
+ "method_missing"],
@label="method_missing",
@lineno=101,
@path="/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb">,
- #<Backtracie::Location:0x0000556486191a00
+ #<Backtracie::Location:0x0000563ca3800df0
@absolute_path="/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
@base_label="hello",
@debug=
["/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
+ "block in hello",
"hello",
- "hello",
- "ClassF#hello",
- 106,
- "ClassF",
+ "block in hello",
+ 107,
+ nil,
false,
"hello",
- "ClassF#hello"],
- @label="hello",
+ "hello"],
+ @label="block in hello",
@@ -252,16 +252,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello",
"hello",
- "ClassF#hello",
+ "hello",
106,
- "ClassF",
+ nil,
false,
"hello",
- "ClassF#hello"],
+ "hello"],
@@ -286,16 +286,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello",
"hello",
- "#<Class:0x0000556485af0a70>.hello",
+ "hello",
121,
- "#<Class:0x0000556485af0a70>",
- true,
+ nil,
+ false,
"hello",
- "#<Class:0x0000556485af0a70>.hello"],
+ "hello"],
@@ -303,16 +303,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello",
"hello",
- "#<Class:0x0000556485af07a0>#hello",
+ "hello",
126,
- "#<Class:0x0000556485af07a0>",
+ nil,
false,
"hello",
- "#<Class:0x0000556485af07a0>#hello"],
+ "hello"],
@@ -320,16 +320,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello",
"hello",
- "#<Module:0x0000556485af0430>.hello",
+ "hello",
132,
- "#<Module:0x0000556485af0430>",
- true,
+ nil,
+ false,
"hello",
- "#<Module:0x0000556485af0430>.hello"],
+ "hello"],
@@ -337,33 +337,33 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"method_with_complex_parameters",
"method_with_complex_parameters",
- "Object#method_with_complex_parameters",
+ "method_with_complex_parameters",
137,
- "Object",
+ nil,
false,
"method_with_complex_parameters",
- "Object#method_with_complex_parameters"],
+ "method_with_complex_parameters"],
@label="method_with_complex_parameters",
@lineno=138,
@path="/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb">,
- #<Backtracie::Location:0x00005564861925e0
+ #<Backtracie::Location:0x0000563ca3801d90
@absolute_path="/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
@base_label="hello",
@debug=
["/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
+ "block (2 levels) in hello",
"hello",
- "hello",
- "ClassJ#hello",
- 146,
- "ClassJ",
+ "block (2 levels) in hello",
+ 148,
+ nil,
false,
"hello",
- "ClassJ#hello"],
- @label="hello",
+ "hello"],
@@ -371,33 +371,33 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello_helper",
"hello_helper",
- "ClassJ#hello_helper",
+ "hello_helper",
142,
- "ClassJ",
+ nil,
false,
"hello_helper",
- "ClassJ#hello_helper"],
+ "hello_helper"],
@label="hello_helper",
@lineno=143,
@path="/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb">,
- #<Backtracie::Location:0x0000556486192928
+ #<Backtracie::Location:0x0000563ca3801f70
@absolute_path="/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
@base_label="hello",
@debug=
["/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
+ "block in hello",
"hello",
- "hello",
- "ClassJ#hello",
- 146,
- "ClassJ",
+ "block in hello",
+ 147,
+ nil,
false,
"hello",
- "ClassJ#hello"],
- @label="hello",
+ "hello"],
@@ -405,16 +405,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello_helper",
"hello_helper",
- "ClassJ#hello_helper",
+ "hello_helper",
142,
- "ClassJ",
+ nil,
false,
"hello_helper",
- "ClassJ#hello_helper"],
+ "hello_helper"],
@@ -422,16 +422,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"hello",
"hello",
- "ClassJ#hello",
+ "hello",
146,
- "ClassJ",
+ nil,
false,
"hello",
- "ClassJ#hello"],
+ "hello"],
@@ -439,16 +439,16 @@
"/ruby/backtracie/spec/unit/interesting_backtrace_helper.rb",
"top_level_hello",
"top_level_hello",
- "Object#top_level_hello",
+ "top_level_hello",
155,
- "Object",
+ nil,
false,
"top_level_hello",
- "Object#top_level_hello"],
+ "top_level_hello"],
We can see that we miss the information about module/class names (we only get methods), we lose the singleton info, etc. The first_lineno
numbers that move (which is not very important since we get the exact line via a different method). The only thing that is correct in the cfp→iseq
version is getting "block in method" in the few places where we were missing it.
So clearly the cme
version in upstream Ruby is correct almost all of the time, except for the label
missing the "block in method" in a few cases.
This seems to point to the "block in method" issue either being an implementation bug (I still don’t quite understand what the two different objects being used here represent) OR more of a "limitation" — perhaps it’s awkward to provide the correct label on the objects that miss it, and since the current MRI object returns one VALUE
per stack frame, not two, the slight issue is just ignored.
-
Benchmarking, performance work
-
Tackle FIXMEs
-
Feature parity for pre-MJIT rubies (is this even possible?)
-
Support showing class name, e.g. https://ivoanjo.me/blog/2020/07/05/ruby-experiment-include-class-names-in-backtraces/
-
Go beyond class name, e.g. https://ivoanjo.me/blog/2020/07/19/better-backtraces-in-ruby-using-tracepoint/
-
Implement equivalents to
Kernel#caller
,Thread#backtrace
-
Implement limits (similar to the arguments passed to the regular Ruby APIs)
-
User documentation
-
Allow efficient sampling for later aggregation (e.g. do as little processing as possible during collection?)