Project

General

Profile

Actions

Feature #17930

open

Add column information into error backtrace

Added by mame (Yusuke Endoh) 13 days ago. Updated 2 days ago.

Status:
Assigned
Priority:
Normal
Target version:
-
[ruby-core:104109]

Description

Consider the following code and error.

data["data"].first["field"] #=> undefined method `[]` for nil:NilClass

There are two possibilities; the variable data is nil, or the return value of first is nil. Unfortunately, the error message is less informative to say which.

This proposal allows to help identifying which method call failed.

$ ruby -r ./sample/no_method_error_ext.rb err1.rb
err1.rb:2:in `<main>': undefined method `[]' for nil:NilClass (NoMethodError)

data["data"].first["field"]
                  ^^^^^^^^^

Proposal

I'd like to propose a feature to get column information from each Thread::BacktraceLocation. Maybe it is good to provide the following four methods:

  • Thread::BacktraceLocation#first_lineno
  • Thread::BacktraceLocation#first_column
  • Thread::BacktraceLocation#last_lineno
  • Thread::BacktraceLocation#last_column

These names came from RubyVM::AbstraceSyntaxTree::Node's methods.

Implementation

Here is a proof-of-concept implementation: https://github.com/ruby/ruby/pull/4540

See https://github.com/ruby/ruby/pull/4540/commits/6ff516f4985826e9f9c5606638001c3c420f7cad for an example usage.
(Note that, currently, you need to build ruby with ./configure cflags=-DEXPERIMENTAL_ISEQ_NODE_ID to enable the feature.)

To put it simply, this PR provides only a raw API, Thread::BacktraceLocation#node_id. To get actual column information, you need to manually identify RubyVM::AbstractSyntaxTree::Node that corresponds to Thread::BacktraceLocation#node_id.
But it would be arguable to expose "node_id", so I will wrap it as the above four methods if this is accepted.

Credit: the original implementation was done by yui-knk (Kaneko Yuichiro).

Drawback

To use this feature, we need to enable -DEXPERIMENTAL_ISEQ_NODE_ID to add "node_id" information (a subtree ID of the original abstract syntax tree) into each byte code instruction. If we provide this feature, the option should be enabled by default. However, the option increases memory consumption.

I performed a simple experiment: I created a scaffold app by rails new, and measured the memory usage after rails s. The result was 97 MB without -DEXPERIMENTAL_ISEQ_NODE_ID, and 100 MB with the option enabled.

In my opinion, it is not so large, but requiring more gems will increase the difference. I will appriciate it if anyone could provide the actual memory increase in a more practical Rails app.

Do you think this feature deserves the memory increase?


Files

image.png (73.3 KB) image.png ttanimichi (Tsukuru Tanimichi), 05/31/2021 12:22 PM

Related issues

Is duplicate of Ruby master - Feature #10982: Clarify location of NoMethod errorOpenActions

Updated by ttanimichi (Tsukuru Tanimichi) 13 days ago

Hi, I like this idea!
This feature would be quite useful when you get NoMethodError in the production environment and error tracking tools like Sentry inform you of that error.
Consider the example I've attached to this comment. This method chain calls Array#[] two times in a line, and you can’t tell which receiver of .[] method calls was nil. To investigate this incident, you need to SSH into the production environment and check what the actual value is. It would be quite inconvenient.

NoMethodError

Updated by matz (Yukihiro Matsumoto) 6 days ago

I agree with the idea too. Let's see how it works.

Matz.

Updated by mame (Yusuke Endoh) 5 days ago

  • Assignee set to mame (Yusuke Endoh)
  • Status changed from Open to Assigned

Thank you matz (Yukihiro Matsumoto) .

I talked with ko1 (Koichi Sasada), and we agreed that allowing RubyVM::AbstractSyntaxTree.of(Thread::Backtrace::Location) is a good approach to allow this feature.

def target
  RubyVM::AbstractSyntaxTree.of(caller_locations[0])
end

p target #=> #<RubyVM::AbstractSyntaxTree::Node:VCALL@5:2-5:8>
# ^^^^^^ Line 5, Column 2--8

I've created a new PR. https://github.com/ruby/ruby/pull/4558

By using this feature, we can implement an error message with column information inside of did_you_mean gem. I'll create another PR later.

Updated by Eregon (Benoit Daloze) 5 days ago

I talked with ko1 (Koichi Sasada), and we agreed that allowing RubyVM::AbstractSyntaxTree.of(Thread::Backtrace::Location) is a good approach to allow this feature.

I strongly disagree, RubyVM is a CRuby-specific API.
This effectively prevents other Ruby implementations to support this new feature for no good reason.

Thread::Backtrace::Location methods are much better and make more sense, and they don't mix unrelated things.

So +1 for this feature, but it MUST be methods on shared public API (on Thread::Backtrace::Location), not RubyVM-specific.

Besides, RubyVM::AbstractSyntaxTree.of(Thread::Backtrace::Location) seems inefficient and brittle as it likely involves parsing, requires the file to exist on the filesystem, etc.
There is no point to use RubyVM::AbstractSyntaxTree when all the information is already in the Thread::Backtrace::Location.

Updated by mame (Yusuke Endoh) 5 days ago

I've created a PR for did_you_mean: https://github.com/ruby/did_you_mean/pull/151

Eregon (Benoit Daloze) wrote in #note-4:

There is no point to use RubyVM::AbstractSyntaxTree when all the information is already in the Thread::Backtrace::Location.

In fact there is no enough information because Thread::Backtrace::Location only knows path and node_id. ko1 (Koichi Sasada) doesn't want to use more memory for this feature and I agree with him. I'm not a big fan of the mechanism of AST.of, but it is a completely different issue from this ticket.

My first proposal was four separate methods, but they require keeping the result of AST.of for each Thread::Backtrace::Location, which requires additional memory.

We may introduce Thread::Backtrace::Location#code_location or something which returns [first_lineno, first_column, last_lineno, last_column]. However, to show the code line clearly, we may need to know the node type (i.e., a method call or something), so I'm not 100% sure if four integers are enough for the use case.

Updated by mame (Yusuke Endoh) 5 days ago

Ahh, I've tried but I found that the current prototype draws an underline from "the end column of the receiver of the call" to "the end column of the call", so four integers are clearly not enough. Hardcoding such a location looks very ad-hoc, so AST::Node is only a reasonable way as far as I think of.

Updated by Eregon (Benoit Daloze) 5 days ago

mame (Yusuke Endoh) wrote in #note-5:

In fact there is no enough information because Thread::Backtrace::Location only knows path and node_id.

This seems an implementation detail, not something that should decide what the API is.

For instance, on TruffleRuby, Thread::Backtrace::Location knows column information (which is stored on nodes), and is represented as a backtrace + index (https://github.com/oracle/truffleruby/blob/master/src/main/java/org/truffleruby/core/thread/RubyBacktraceLocation.java).
There is no need to re-parse anything, and requiring reparsing for this feature seems really suboptimal (slow) and prone to issues if e.g., the file no longer exists.

Wouldn't a byte offset + byte length be almost as compact as node_id, but without needing to keep the node or to reparse?

ko1 (Koichi Sasada) doesn't want to use more memory for this feature and I agree with him. I'm not a big fan of the mechanism of AST.of, but it is a completely different issue from this ticket.

My first proposal was four separate methods, but they require keeping the result of AST.of for each Thread::Backtrace::Location, which requires additional memory.

The footprint of a Thread::Backtrace::Location does not seem a big issue, those objects are typically GC'd pretty quickly.
Why would they require to keep the result of AST.of?
Can the column information be kept from the parser in the first place?

Ahh, I've tried but I found that the current prototype draws an underline from "the end column of the receiver of the call" to "the end column of the call", so four integers are clearly not enough. Hardcoding such a location looks very ad-hoc, so AST::Node is only a reasonable way as far as I think of.

Could you show the output of that? I'm not sure I follow the decription.

I think whatever the API is we should also design something for did_you_mean that can work on other Ruby implementations.

As far as I see, RubyVM::AbstractSyntaxTree exposes MRI internals (e.g., node types, node field names, internal node field order) and seems difficult to support on other Ruby implementations (it reaches deep in MRI internals).
did_you_mean is a public gem, so I think it should avoid using such a internal, unstable (the AST will evolve and differs per Ruby implementation), and MRI-specific API.
For instance, nd_recv = nd_call.children[0] feels hacky (should be call_node.receiver or call_node[:receiver]), and hardcoding node types feel brittle (e.g., what if there is a new call node type?)

It would be great to turn RubyVM::AbstractSyntaxTree into a proper API which can be supported on other Ruby implementations, and then it could be used by many other gems.
I think that would require to have proper names and more thinking towards making it more future proof.

Updated by ioquatix (Samuel Williams) 5 days ago

I agree we should introduce an abstract rich model for this.

https://bugs.ruby-lang.org/issues/13383 is a similar problem.

It makes sense to me to introduce some kind of Backtrace::Location#source_location.

We should stop thinking about arrays of integers and think about a rich interface, even so far as having read method that returns the code in question (reading from disk doesn't always work after the fact).

It makes a lot more sense to me and I think easier for people to consume with a well defined interface.

Updated by mame (Yusuke Endoh) 4 days ago

did_you_mean is a public gem, so I think it should avoid using such a internal, unstable (the AST will evolve and differs per Ruby implementation), and MRI-specific API.

That makes sense.

First I tried to implement the feature in prelude.rb. However, the approach made MJIT tests fail because it changes JIT invocation count that is checked by the tests. So ko1 (Koichi Sasada) suggested to implement the feature in a builtin gem required by default like did_you_mean. However, indeed it has a problem you stated.

I'll try to implement it again in prelude.rb, or think of creating a private, MRI-specific default gem.

Updated by Eregon (Benoit Daloze) 4 days ago

I'll try to implement it again in prelude.rb, or think of creating a private, MRI-specific default gem.

Why not exposing column information on Thread::Backtrace::Location?
That would be a proper public API.
Given that Thread::Backtrace::Location already exposes code locations (path and line currently), it feels natural that it can provide column information too.

Is the problem that does not show the proper place for the call and underlines the receiver too?

This feature should really be available on all Rubies, not just CRuby, so I think we need to expose proper APIs to make it work.

Another possibility might be for NoMethodError#message to already include the underlining (and be multiple lines then),
or to add a method on NoMethodError that would returns the underlying String or column information.
Of course that would be less general and be useful for fewer use cases.

Updated by Eregon (Benoit Daloze) 4 days ago

Another thought: for the case of NoMethodError, maybe showing the arguments would be enough to differentiate in most cases which of the two calls with the same name was problematic?
NoMethodError#args already exists, so it would be the matter of showing it in the exception message.

Updated by yuki24 (Yuki Nishijima) 4 days ago

Another thought: for the case of NoMethodError, maybe showing the arguments would be enough to differentiate in most cases which of the two calls with the same name was problematic?
NoMethodError#args already exists, so it would be the matter of showing it in the exception message.

I don't think it is ideal. If you chain #map in one line and got a nil by accident during development then checking the number of args may not be helpful.

Just FYI here is the same request from over 6 years ago: https://bugs.ruby-lang.org/issues/10982

Actions #13

Updated by mame (Yusuke Endoh) 4 days ago

  • Is duplicate of Feature #10982: Clarify location of NoMethod error added

Updated by mame (Yusuke Endoh) 4 days ago

If needed, we can implement Thread::Backtrace::Location#code_location by using AST.of.

class Thread::Backtrace::Location
  def code_location
    node = RubyVM::AbstractSyntaxTree.of(self)
    [
      node.first_lineno,
      node.first_column,
      node.last_lineno,
      node.last_column,
    ]
  end
end

If Eregon (Benoit Daloze) wants this, we may introduce this as a built-in method. But as yuki24 (Yuki Nishijima) said, I believe this is less useful because it is too rough for the underline feature.

Updated by Eregon (Benoit Daloze) 2 days ago

mame (Yusuke Endoh) wrote in #note-14:

If needed, we can implement Thread::Backtrace::Location#code_location by using AST.of.
If Eregon (Benoit Daloze) wants this, we may introduce this as a built-in method.

I think it is good to add, as basically Thread::Backtrace::Location-backtraces (caller_locations, backtrace_locations) then get column information, which might be nice in debugger, user-formatted backtraces (e.g. in HTML one could highlight that region of code), etc.

But as yuki24 (Yuki Nishijima) said, I believe this is less useful because it is too rough for the underline feature.

To clarify, you mean it would show:

data["data"].first["field"].bar
^^^^^^^^^^^^^^^^^^^^^^^^^^^
json.first.fisrt.bar
^^^^^^^^^^^^^^^^

instead of:

data["data"].first["field"].bar
                  ^^^^^^^^^
json.first.fisrt.bar
          ^^^^^^

That seems enough to know which one it was, but it is indeed less clear.

mame (Yusuke Endoh) How do you think about something like NoMethodError#code_location (or some other name) that would return the lines&cols for that second region?
I think that would be possible when we have the call node or bytecode's node_id, and then can find the receiver node's last column (& line) from there.
It might not always be available, e.g., from public_send or from rb_funcall(), but that seems unavoidable anyway.

Actions

Also available in: Atom PDF