Feature #21501: Include native filenames in backtraces as sources for native methods

• Status: Open
• Assignee: -
• Target version: -

[ivoanjo (Ivo Anjo)]

Consider this example:

require 'bigdecimal'

BigDecimal.singleton_class.prepend(
  Module.new do
    def save_rounding_mode
      super
    end
  end
)

[:example].each do
  BigDecimal.save_rounding_mode do
    puts caller
    sleep 1
  end
end

which Ruby will print as (from 3.4, since https://bugs.ruby-lang.org/issues/19117):

native-filenames-example.rb:6:in 'BigDecimal.save_rounding_mode'
native-filenames-example.rb:6:in 'save_rounding_mode'
native-filenames-example.rb:12:in 'block in <main>'
native-filenames-example.rb:11:in 'Array#each'
native-filenames-example.rb:11:in '<main>'

Having the class names helps, but I think this behavior can still be confusing. Without looking at the code, and understanding that Array#each and BigDecimal.save_rounding_mode are written in native code, it can be confusing to see them be assigned to native-filenames-example.rb in the backtrace.

I would like to propose that, whenever possible (see notes below), Ruby shows the name of the native filename where a method was defined. This would result on the backtrace becoming:

/rvm/gems/ruby-3.4.4/gems/bigdecimal-3.2.2/lib/bigdecimal.so:0:in 'BigDecimal.save_rounding_mode'
native-filenames-example.rb:6:in 'save_rounding_mode'
native-filenames-example.rb:12:in 'block in <main>'
/rvm/rubies/ruby-3.4.4/lib/libruby.so.3.4:0:in 'Array#each'
native-filenames-example.rb:11:in '<main>'

or, alternatively, this mechanism could be applied only to extensions, not to libruby/the ruby binary (it's not particularly hard to detect and exclude it):

/rvm/gems/ruby-3.4.4/gems/bigdecimal-3.2.2/lib/bigdecimal.so:0:in 'BigDecimal.save_rounding_mode'
native-filenames-example.rb:6:in 'save_rounding_mode'
native-filenames-example.rb:12:in 'block in <main>'
native-filenames-example.rb:11:in 'Array#each' # Don't touch array ;)
native-filenames-example.rb:11:in '<main>'

This would make it even easier to understand what's coming from where, and I believe it's a great complement to showing the class names.

Furthermore, displaying the actual native libraries matches really well with the semantics we get for regular Ruby files: if I were to look on my machine, I would see /rvm/gems/ruby-3.4.4/gems/bigdecimal-3.2.2/lib/bigdecimal.so and /rvm/rubies/ruby-3.4.4/lib/libruby.so.3.4. And if I moved them, or overrode them, and loaded them from a different path, I would see the difference. (I say this because in the past I've thought about displaying the actual source .c files and lines, but that a) requires debug information; and b) the files often no longer exist in the filesystem; c) is much harder to implement cross-os).

Edit: This also matches with $LOADED_FEATURES, which also include the .so files as well.

---

The extra cool thing is that this is really, really easy to implement!

I actually created a micro gem to show this off as well as added this as a feature to the Datadog Ruby profiler. Other than checking for headers and whatnot, fetching the info can be implemented in 41 lines of C: https://github.com/ivoanjo/native-filenames/blob/main/ext/native_filenames_extension/native_filenames_extension.c#L45-L86 and works in Linux, macOS and Windows!

The way it works is, we can use the function pointer passed to rb_define_method, looking it put using dladdr (or some of the other variants shown in the code). Then, given just the function pointer, we can get a path back. It's as simple as that -- it can be added transparently as part of storing the cfunc.

And if for some reason the path is not available, we could fall back to the current behavior.

I'd be very happy to contribute a PR to make this change, but I decided to start with a proposal first as I realize not everyone may be as excited about this idea as I am ;)

[nobu (Nobuyoshi Nakada)]

I don't think it will need such platform specific code.
Probably it would be possible by:

• in require_internal, store the loading path on struct rb_ext_config.
• in setup_method_cfunc_struct, copy the path to rb_method_cfunc_t.
• in location_to_str, use the path if location_cfunc_p(loc) and the path is stored.

[ivoanjo (Ivo Anjo)]

I don't think it will need such platform specific code.
Probably it would be possible by: [...]

I'm thinking that in this case it would only work with methods defined when the extension gets loaded (e.g. inside require_internal), not later.

Having said that, those methods are probably 99.9999...% if not 100% of all methods from native gems so yeah I'd expect little difference in practice.

[ivoanjo (Ivo Anjo)]

• Description updated (diff)

[Eregon (Benoit Daloze)]

It seems nice, but I think it would be even more helpful to show lines in C files.
I think this could be achieved by defining rb_define_method as a macro using __FILE__ and __LINE__ and that should be perfectly portable (and doesn't require debug info).

FWIW TruffleRuby 23.1 shows lines in C files thanks to running on top of Sulong:
https://github.com/eregon/actions-shell/actions/runs/16128506338/job/45510989176#step:4:5

/home/runner/.rubies/truffleruby-23.1.2/lib/truffle/truffle/cext.rb:1094:in `rb_yield'
call.c:95:in `rb_yield'
/home/runner/.rubies/truffleruby-23.1.2/lib/truffle/truffle/cext.rb:1069:in `execute_without_conversion'
/home/runner/.rubies/truffleruby-23.1.2/lib/truffle/truffle/cext.rb:1069:in `block in rb_protect'
/home/runner/.rubies/truffleruby-23.1.2/lib/truffle/truffle/cext.rb:1068:in `capture_exception'
/home/runner/.rubies/truffleruby-23.1.2/lib/truffle/truffle/cext.rb:1068:in `rb_protect'
exception.c:42:in `rb_protect'
bigdecimal.c:3870:in `BigDecimal_save_rounding_mode'
/home/runner/.rubies/truffleruby-23.1.2/lib/truffle/truffle/cext_ruby.rb:42:in `save_rounding_mode'
test.rb:6:in `save_rounding_mode'
test.rb:12:in `block in <main>'
test.rb:11:in `each'
test.rb:11:in `<main>'

[matz (Yukihiro Matsumoto)]

I didn't quite understand what makes you happy with this proposal. Could you explain a little more how it would be useful? In my opinion, the typical Ruby user is not interested in line numbers in C source code or names of extension libraries.

Matz.

[ivoanjo (Ivo Anjo)]

For me the usefulness is in understanding both what and where something is happening even without needing to go into the source code.

E.g. Let's consider that native extensions didn't exist. If I get an error in production and I see a stack trace:

/rvm/gems/ruby-3.4.4/gems/bigdecimal-3.2.2/lib/bigdecimal.rb:123:in 'BigDecimal.save_rounding_mode'
native-filenames-example.rb:6:in 'save_rounding_mode'
native-filenames-example.rb:12:in 'block in <main>'
/rvm/rubies/ruby-3.4.4/lib/libruby.rb:456:in 'Array#each'
native-filenames-example.rb:11:in '<main>'

Even without looking at any code, I can understand -- "oh, something happened inside the bigdecimal gem, and there's also something from the Ruby standard library a bit further below".

Seeing only this:

native-filenames-example.rb:6:in 'BigDecimal.save_rounding_mode'

Does not get me as much information: I'd need to "know" by heart what the bigdecimal gem is, and possibly understand that some things (cfuncs) don't show in the same way in the stack trace. And even then -- is it the bigdecimal gem, or is it another BigDecimal class in the code?

Zooming in on this part:

(...) possibly understand that some things (cfuncs) don't show in the same way in the stack trace.

I think this part can be a bit confusing. I just checked my editions of "Programming Ruby" and "The Well-Grounded Rubyist" and I could not find any references to this behavior. At least for me, it was just something I picked up by looking at enough stack traces: "oh, in this case it was actually a native method and the file doesn't show up".

I agree that the "typical Ruby user" would probably not want to modify the extension code. I guess my thesis is: It seems useful to at show users they exist, since they are part of the application? This is an opportunity to teach about this feature, and even make it clear when native extensions are present while debugging problems. Seems easier to google "why am I having problems with Ruby's bigdecimal.so" :)

Having learned about them, users can make a more informed choice about using gems with native code vs with Ruby code. Before, they might not even have realized they had them in their important "hot paths" for the application.

Or, saying it in another way, if I can require an hello.rb that gives me a HelloClass#print_hello in Ruby code, and see

hello.rb:123: in 'HelloClass#print_hello'

I think it would be nice that I could require an hello.so that gives me an HelloClass#print_hello and get

hello.so: in 'HelloClass#print_hello'

(And as I mentioned above, this matches well with $LOADED_FEATURES also showing hello.so)

---

It seems nice, but I think it would be even more helpful to show lines in C files.

I must admit I'm a bit torn on this. As I mentioned above, often the .c files are not kept around in the filesystem, whereas in my proposed version I'm showing the exact file (including path) that got loaded into the Ruby VM and that provides the method I'm using.

Having said that, I think having the .c files/lines as extra information that can get recorded is useful too. Aka I would go for showing the the .so by default, but record both and make both available in the Backtrace::Locations.

I think this could be achieved by defining rb_define_method as a macro using FILE and LINE and that should be perfectly portable (and doesn't require debug info).

The small hiccup with this approach for the line __LINE__ is that it would be the call site for rb_define_method, and not where the function itself was defined. TBH I would love to have the actual first line for the function... having it pointing at the rb_define_method is a bit less useful?

(That said -- methods are almost always defined in the same file as they were declared, so ignoring the __LINE__, I agree adding __FILE__ would work well)

[Eregon (Benoit Daloze)]

matz (Yukihiro Matsumoto) wrote in #note-5:

In my opinion, the typical Ruby user is not interested in line numbers in C source code or names of extension libraries.

I think most are or would not mind, because it is always valuable to have more clarity when an exception happens or when debugging.
My thinking here is similar to it's never good to silently swallow exceptions: it hurts debugging and the ability to understand programs.

native-filenames-example.rb:6:in 'BigDecimal.save_rounding_mode' pretends that the BigDecimal.save_rounding_mode is defined in native-filenames-example.rb, but it is not true, and that filename is not useful information, it's already shown in the next backtrace line.
Having bigdecimal.so:0:in 'BigDecimal.save_rounding_mode' or bigdecimal.c:3870:in 'BigDecimal.save_rounding_mode' makes it immediately clear this is defined in a native extension, and if e.g. if an exception comes from there it's much clearer where to look to find out the source of it, etc.

[Eregon (Benoit Daloze)]

ivoanjo (Ivo Anjo) wrote in #note-6:

I must admit I'm a bit torn on this. As I mentioned above, often the .c files are not kept around in the filesystem, whereas in my proposed version I'm showing the exact file (including path) that got loaded into the Ruby VM and that provides the method I'm using.

Actually most .c files would be kept around, for user-installed gems with native extensions.
But yes for default & bundled gems & core library methods they might not be around. It would still be useful though as e.g. one could easily lookup the source file on GitHub for the corresponding release.
Some integration could even automatically show the source, e.g. in the Rails error page or in some editor/IDE.

The small hiccup with this approach for the line __LINE__ is that it would be the call site for rb_define_method, and not where the function itself was defined. TBH I would love to have the actual first line for the function... having it pointing at the rb_define_method is a bit less useful?

Ah true, I forgot about that detail.
I think it's much better than no line but indeed ideally it would show the line where the function itself is defined but I guess there is no easy way to get that.
The rb_define_method line is already pretty good though as that will show which C function implements it, and then it's a trivial search to find it (in the 99% cases it's in the same file, and otherwise a search e.g. on the GitHub repository or gem directory would find it).

Another advantage is the .c file and line would be constant across platforms, and it's clear it's "C extension code".
The library name changes per platform e.g. bigdecimal.so vs bigdecimal.bundle, which can e.g. make googling for a given exception stacktrace more difficult (and doesn't say which language it is but that's pretty minor).

[mame (Yusuke Endoh)]

Let me clarify why the current behavior is generally preferred.

The underlying premise is that a bug is far more likely to be in the user's Ruby code than in the C extensions.

Therefore, a line like:

native-filenames-example.rb:6:in 'BigDecimal.save_rounding_mode': ... error

...concisely points to the most relevant location for the user to inspect first. In most cases, debugging simply involves fixing the code at or around this exact location.

If the backtrace instead pointed to a line in .../bigdecimal.so or .../bigdecimal.c, the user would have to scan down the trace to find the first line corresponding to their own .rb file. This adds an unnecessary step and cognitive cost to the daily debugging process.

In short, the current behavior is optimized for the most common use case: efficiently debugging the frequent, simple bugs in one's own application code. To justify changing this, we would need a strong and clear reason that outweighs this benefit.

[ivoanjo (Ivo Anjo)]

• File 456551323-180e85e7-52dc-43d1-9a91-cd7a254de10b.png 456551323-180e85e7-52dc-43d1-9a91-cd7a254de10b.png added

The underlying premise is that a bug is far more likely to be in the user's Ruby code [...]

Yup, I can very very much understand this argument.

We actually have a feature on the datadog ruby profiler which we call "only my code" which TL;DR collapses frames in stdlib and gems (you can select which view you want). When I added native filenames to the profiler I even included this screenshot with that feature enabled, to show it was still working:

This collapsing works even if there are multiple frames in gems, e.g. it produces a shorter and easier to read backtrace (which is especially nice in something like a Rails app).

That said... going back to...

The underlying premise is that a bug is far more likely to be in the user's Ruby code than in the C extensions.

I'm curious about the classification "than in the C extensions" in the end of your sentence. Specifically, I would say "the bug is far more likely to be in the user's Ruby code" without mentioning C extensions.

Which is what gets me back to my original proposal: I think it's weird that native extensions are treated specially. If Ruby hides bigdecimal.so to make it easier to spot the bug in the user's code, why not hide bigdecimal.rb (or lib/bigdecimal/*.rb to be more exact)?

In fact, the collapsing I showed for the datadog profiler above indeed works for either -- it will show "bigdecimal" for any ruby files in the bigdecimal gem, as well as for the .so.

I do agree for libruby.so that it might be a bit too much -- it'll be extremely rare that the bug will be on Array#each so I think that's a great argument for this change affecting only native extensions and not things inside the Ruby VM (or even default gems?).