Project

General

Profile

Actions

Feature #19117

closed

Include the method owner in backtraces, not just the method name

Added by byroot (Jean Boussier) almost 2 years ago. Updated 8 months ago.

Status:
Closed
Target version:
[ruby-core:110683]

Description

module Foo
  class Bar
    def inspect
      1 + '1'
    end
  end
end

p Foo::Bar.new

This code produce the following backtrace:

/tmp/foo.rb:4:in `+': String can't be coerced into Integer (TypeError)
	from /tmp/foo.rb:4:in `inspect'
	from /tmp/foo.rb:9:in `p'
	from /tmp/foo.rb:9:in `<main>'

This works, but on large codebases and large backtraces the method name isn't always all that revealing, most of the time you need to open many of the locations listed in the backtrace to really understand what is going on.

I propose that we also include the owner name:

/tmp/foo.rb:4:in `Integer#+': String can't be coerced into Integer (TypeError)
	from /tmp/foo.rb:4:in `Foo::Bar#inspect'
	from /tmp/foo.rb:9:in `Kernel#p'
	from /tmp/foo.rb:9:in `<main>'

I believe that in many case it would allow to much better understand the backtrace without having to jump back and forth between it and the source code.

This is inspired by @ivoanjo (Ivo Anjo) 's backtracie gem: https://github.com/ivoanjo/backtracie


Related issues 2 (0 open2 closed)

Related to Ruby master - Feature #16495: Inconsistent quotes in error messagesClosedmatz (Yukihiro Matsumoto)Actions
Related to Ruby master - Feature #20275: Avoid extra backtrace entries for rescue and ensureClosedEregon (Benoit Daloze)Actions

Updated by zverok (Victor Shepelev) almost 2 years ago

It will probably be helpful, but somewhat unpredictable. If we are using method.owner.inspect, it might do this, say, in Rails (which redefines model classes' #inspect for "informativeness"):

app/models/organization.rb:458:in `Organization(id: integer, name: string, created_at: datetime, updated_at: datetime, ....and so on, 35 fields in total...)#inspect`

Updated by Eregon (Benoit Daloze) almost 2 years ago

+1, it's nice and useful.
I think we should always use the original definition of Module#inspect to show the module name, and don't call the dynamic inspect which can lie.

As an anecdote TruffleRuby already uses this format for backtrace entries of other languages, and it would be more consistent to do the same for Ruby too.

Updated by Eregon (Benoit Daloze) almost 2 years ago

Also this is particularly useful to understand backtrace entries corresponding to core methods like Kernel#p above, as the file:line does not help for those entries.

Updated by byroot (Jean Boussier) almost 2 years ago

If we are using method.owner.inspect

Maybe I should have specified it, but no, that's not what I have in mind. There is a function in MRI to get the "fully qualified name" of a module/class, and it doesn't go through #inspect.

So custom inspect on module/class are not a concern.

Updated by kjtsanaktsidis (KJ Tsanaktsidis) almost 2 years ago

+1 to this!

I also literally just opened https://bugs.ruby-lang.org/issues/19119 tonight as well which touches on this (as well as some other things) - but maybe to keep the discussion here, some fun cases to consider include Refinements, singleton classes (which are not singleton classes of a class, but rather of a non-class object), and anonymous classes. I think the current implementation of rb_class_path will print a string like "#<Class:0xdeadbeef>" or "#<Module:0xdeadbeef>" in at least some situations like this. This is not all that useful IMO, and those addresses are not even stable across the lifetime of a single program (they're just %p formatting the VALUE, which will change if the object gets compacted, right?).

The other reason to care about having addresses like that in names - it will break aggregation of stack frames in e.g. profiling tools, or exception trackers. If you have a function like def foo(n); def n.bork; raise "bork"; end; n.bork; end; it would come up with a new stack frame every time in e.g. Sentry or Rollbar or what have you.

Instead, I would propose printing something like... (shamelessly stolen mostly from Backtracie)...

  • "#<refinement Foo of Bar>" for a refinement module adding methods to
    Bar
  • "#<instance of Foo>" for a particular instance of Foo
  • "#<singleton of Foo>" for Foo's singleton class.
  • "#<anonymous subclass of Foo>" for an anonymous subclass
  • The usual classpath string otherwise

These three commits show what that might look like -

EDIT - one more case to think of - while we're changing this, WDYT about making it print how a method was called if it was aliased? like

	from /tmp/foo.rb:4:in `Foo::Bar#my_custom_inspect' (aliased as `#inspect`)

Updated by Eregon (Benoit Daloze) almost 2 years ago

Refinements are already formatted like:

$ ruby -e 'module M; refine String do; p self; end; end'
#<refinement:String@M>

I think there is no need to change anything there.

For methods on a singleton class, I believe we should use the . notation, so Process.pid instead of #<Class:Process>#pid.

We cannot avoid addresses/object_id's in the output, there can be truly anonymous modules.
But I agree that a changing address is not great.
What TruffleRuby does is use the object_id for Kernel#inspect/Module#inspect. That's stable.
I think CRuby should do the same.
The changing inspect for the same object is indeed very confusing, cc @tenderlovemaking (Aaron Patterson):

> obj=Object.new
=> #<Object:0x00000000029dda80>
> GC.compact
> obj
=> #<Object:0x00000000022e96e8>

It doesn't need to be object_id, but it needs to be stable per object, so using object_id seems nice and avoids the need for another kind of identity hash/id (and the storage for it).
It could also be for instance the Kernel#hash (the identity hash) of that object, and that is stable (EDIT: it seems the identity hash is based on object_id on CRuby, so it's basically the same thing).

Updated by byroot (Jean Boussier) almost 2 years ago

@kjtsanaktsidis (KJ Tsanaktsidis) I understand what you are trying to do, but I think it's orthogonal to the current issue.

I'll quickly answer here, but it's probably best to discuss that in your issue instead.

I don't think object_id will cut it. They are incremental and lazy, which means they're unlikely to match across processes. (@Eregon (Benoit Daloze) see https://www.youtube.com/watch?v=xoGJPtNp074 for what they are trying to do, basically they want stable identifier across a large fleet of server)

The only reasonable stable identification data I can think of (and that would be nice for other reasons) would be to display the source location, like for procs:

p ->() {}
p Class.new
#<Proc:0x000000010f87d970@/tmp/foo.rb:1 (lambda)>
#<Class:0x000000010f87d740>

So that it would look like:

#<Proc:0x000000010f87d970@/tmp/foo.rb:1 (lambda)>
#<Class:0x000000010f87d740@/tmp/foo.rb:2>

The problem with this is that it's not an information we have store right now, so it would be an overhead.

So I really encourage you to open a dedicated issue on what a better default Module#inspect method could be.

Updated by Eregon (Benoit Daloze) almost 2 years ago

Agreed the better default Module#inspect is a mostly separate thing (matching across processes is too difficult IMHO, and there might be multiple modules created on the same file:line so we need to show the ID anyway).
It's also fairly rare to have anonymous modules on the stack.

I think the one thing we should do is special handling of singleton classes to use the . notation instead, since that improves readability quite a bit.

Updated by byroot (Jean Boussier) almost 2 years ago

I think the one thing we should do is special handling of singleton classes to use the . notation instead, since that improves readability quite a bit.

Yes. I didn't mention it because I thought it was implied. The idea is to use the exiting common syntax for fully qualified method names.

Updated by kjtsanaktsidis (KJ Tsanaktsidis) almost 2 years ago

OK, so if I understand correctly, the proposal in this ticket is to make Thread::Backtrace::Location#inspect and Kernel#callers print method names using the algorithm used in rb_profile_frame_qualified_method_name. Currently, they just print either iseq->body->location.label or cme->def->original_id.

The algorithm used by rb_profile_frame_qualified_method_name is:

  • Look up the defined_class for the method entry
  • If it's a singleton class, and the thing it's a singleton class of is a Class/Module: print rb_class_path(attached) + "."
  • If it's a singleton class, and the thing it's a singleton class of is NOT a Class/Module: print "#<" + rb_class2name(class of attached) + ":" + hex of the VALUE address + ">" + "."
  • Otherwise, print: rb_class_path(klass) + "#"
  • Then print cme->def->original_id

This ticket would handle making this change ONLY. The motivation for this change is purely to give better developer ergonomics.

What I wanted to do was change the output to not include any %p representations of VALUE's at all - neither the one directly in rb_profile_frame_classpath, nor the one in make_temporary_path in variable.c called via rb_class_path. It sounds like you're saying I should make a separate proposal for that?

In fact - perhaps it might be best not to change the default output of anything at all for my proposal, and simply add a keyword argument Thread::Backtrace::Location#inspect, Thread::Backtrace::Location#label (and probably also Module, Method, etc) to print representations without addresses in them, by simply making them all 0x0 or something. This would avoid us having divergent representations of how to print fully-qualified methods whilst also achieving some sensible way to get rid of addresses for backtrace aggregations.

Updated by kjtsanaktsidis (KJ Tsanaktsidis) almost 2 years ago

Also - if I've got this right, I'm happy to write up a patch to implement this proposal - I've been playing around in this area of the code so I think I know what to do.

Updated by byroot (Jean Boussier) almost 2 years ago

@kjtsanaktsidis (KJ Tsanaktsidis) thanks for proposing to implement the patch, but don’t worry I’ll do it.

Updated by Eregon (Benoit Daloze) almost 2 years ago

kjtsanaktsidis (KJ Tsanaktsidis) wrote in #note-10:

This ticket would handle making this change ONLY. The motivation for this change is purely to give better developer ergonomics.

Correct. To be able to understand much more from the backtrace without needing as much to look in every file:line.

It sounds like you're saying I should make a separate proposal for that?

Yes. (for that use case I think it's much better if you can use e.g. caller_locations/Thread::Backtrace::Location to achieve the output you want, or just post-process the output).

Updated by mame (Yusuke Endoh) almost 2 years ago

I agree with this proposal in general.

As everyone is concerned, I don't think #inspect should be used to display receivers. I think it will lead to a worse version of the issue of https://bugs.ruby-lang.org/issues/18285.

One idea: We may implement only the major cases (Foo#some_instance_method and Foo.some_class_method) using Class#name, and leave the other complecated cases (such as refinements and singleton classes of a non-class object) with only the method name as before.

Updated by ivoanjo (Ivo Anjo) almost 2 years ago

+1 thanks for looking into this. Happy to help out as well, since I'm quite interested in it! :)

One case where I find this especially useful is for methods implemented in C because currently they get blamed on the file/line of the last Ruby frame on the stack, and sometimes that can get really confusing to follow (Mame mentioned https://bugs.ruby-lang.org/issues/18285 and when I was debugging this I had to break out backtracie to understand what was going on as the stack traces didn't make a lot of sense).

This would also be very useful for profilers and other tools that work with stack traces :)

Updated by Dan0042 (Daniel DeLorme) almost 2 years ago

I'd like to clarify if we're really talking about showing the owner or the receiver of the method?

class Foo
  def inspect
    raise "hmm"
  end
end

class Bar < Foo
end

Bar.new.inspect
#/path/to/foo.rb:3:in `Foo#inspect': hmm (RuntimeError)
#or
#/path/to/foo.rb:3:in `Bar#inspect': hmm (RuntimeError)

The owner is usually/often right there in the filepath, so I would tend to think the receiver is more useful information.

Updated by byroot (Jean Boussier) almost 2 years ago

we're really talking about showing the owner or the receiver of the method?

My suggestion is for the owner. Simply put because it matches the path and other existing method representations.

But I can see arguments about showing the receiver instead, and I am open to this.

The owner is usually/often right there in the filepath

Not all code follow a convention where classes map to files 1 to 1.

Updated by Eregon (Benoit Daloze) almost 2 years ago

It must be the owner, anything else would be very confusing.
I believe nobody wants String#then (there is no such method), they want to see Kernel#then.
Also the receiver class is problematic to define (do we care about the singleton class if the receiver has one, etc), and it might not be available when making backtraces (e.g. it isn't on TruffleRuby).

Updated by Eregon (Benoit Daloze) almost 2 years ago

Dan0042 (Daniel DeLorme) wrote in #note-16:

The owner is usually/often right there in the filepath

That's not the case for methods defined in C (either core or C extensions) as mentioned above, so it's a significant help to read and understand the backtrace to have the owner there.

Updated by Dan0042 (Daniel DeLorme) almost 2 years ago

Not all code follow a convention where classes map to files 1 to 1.

And that's why I wrote "usually/often", not "always".

That's not the case for methods defined in C (either core or C extensions) as mentioned above, so it's a significant help to read and understand the backtrace to have the owner there.

Ok thank you, I missed that above.

But I want to point out that since usually ruby code is written with the convention that classes map to files 1 to 1, and since the owner is right there in the filepath for the methods that are defined in ruby, for the majority of the stack trace you're going to see a lot of redundancy. ex:

/home/me/test/superspeed/server/events/socket/base.rb:7:in `Superspeed::Server::Events::Socket::Base#test': todo (RuntimeError)
	from /home/me/test/superspeed/server/events/socket/comm.rb:9:in `Superspeed::Server::Events::Socket::Comm#test1'
	from /home/me/test/superspeed/server/events/socket/comm.rb:18:in `<main>'

PS: this is not an argument in favor of showing the receiver or owner; there's going to be a lot of redundancy in either case.

Updated by mame (Yusuke Endoh) almost 2 years ago

Discussed at the dev meeting. @matz (Yukihiro Matsumoto) was basically positive for this proposal. But there is still much to discuss and experiment, so it was decided to discuss for Ruby 3.3.

  • How much impact does exception generation have on performance? (Each frame of the backtrace needs to maintain self)
  • What notation to use (not discussed at this dev meeting due to priority on Ruby 3.2 issues)

Updated by mame (Yusuke Endoh) 11 months ago

Let's discuss this towards Ruby 3.4 :cry:

Updated by byroot (Jean Boussier) 11 months ago

  • Target version set to 3.4

Agreed. I took the liberty to create a 3.4 target version and add it.

Updated by Eregon (Benoit Daloze) 11 months ago

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

  • How much impact does exception generation have on performance? (Each frame of the backtrace needs to maintain self)

That's a good point. While the method name can be stored in the bytecode or so, not so much for the module name (especially since it can get a proper name later).
In many cases it can be known statically or is the same when defining the method, but not always (e.g. MyStruct = Struct.new(:x) { def foo; end; }).
Maybe we should only use this notation when the module name/path is known statically?

Actions #25

Updated by mame (Yusuke Endoh) 10 months ago

  • Related to Feature #16495: Inconsistent quotes in error messages added

Updated by mame (Yusuke Endoh) 10 months ago

I prototyped this proposal: https://github.com/ruby/ruby/pull/9605

Fortunately, this would bring neither perrformance degredation nor extra memory usage when an exception is raised because I just replaced the method id with the method entry object in Thread::Backtrace::Location. (To get the method id, we need to read it via the method entry object, but I believe it is ignorable.)

The notation is as follows.

  • Instance methods of named classes are ClassName#method_name.
  • Class methods for named classes are ClassName.method_name.
  • Only method_name otherwise

I think I properly support block in ClassName#method_name and so on.

$ cat test.rb
def toplevel = raise

class Foo
  def self.class_meth = toplevel

  def instance_meth = Foo.class_meth
end

obj = Foo.new

def obj.singleton_meth = instance_meth

obj.singleton_meth

$ ./miniruby test.rb
test.rb:1:in 'Object#toplevel': unhandled exception
        from test.rb:4:in 'Foo.class_meth'
        from test.rb:6:in 'Foo#instance_meth'
        from test.rb:11:in 'singleton_meth'
        from test.rb:13:in '<main>'

@byroot (Jean Boussier) What do you think?

This causes some tests to fail, but I haven't fixed the test yet.

Updated by byroot (Jean Boussier) 10 months ago

What do you think?

I think it's beautiful. I'll try to get some time to build your branch and play with it, see how it behave in more corner-casy situations.

Updated by byroot (Jean Boussier) 10 months ago

I tried the following (contrived) script:

class Abstract
  def oops
    yield
  end
end

class Concrete < Abstract
  class << self
    def oops(&block)
      new.oops { 1 + "1" }
    end
  end

  def oops(&block)
    tap do
      super(&block)
    end
  end
end

Concrete.method(:oops).call

3.3:

test.rb:10:in `+': String can't be coerced into Integer (TypeError)
	from test.rb:10:in `block in oops'
	from test.rb:3:in `oops'
	from test.rb:16:in `block in oops'
	from <internal:kernel>:90:in `tap'
	from test.rb:15:in `oops'
	from test.rb:10:in `oops'
	from test.rb:21:in `call'
	from test.rb:21:in `<main>'

Your branch:

./test.rb:10:in `Integer#+': String can't be coerced into Integer (TypeError)
	from ./test.rb:10:in `block in Concrete.oops'
	from ./test.rb:3:in `Abstract#oops'
	from ./test.rb:16:in `block in Concrete#oops'
	from <internal:kernel>:90:in `Kernel#tap'
	from ./test.rb:15:in `Concrete#oops'
	from ./test.rb:10:in `Concrete.oops'
	from ./test.rb:21:in `Method#call'
	from ./test.rb:21:in `<main>'

I think it very significantly improve the backtrace readability. Things like call becoming Method#call is really great.

I also love in your example that toplevel is displayed as Object#toplevel, I think it could help quite a few people realize that defining a method at the top level defines it in Object.

Updated by Dan0042 (Daniel DeLorme) 10 months ago

Please try it with a Rails backtrace, so you get something like:

#before
from /opt/ruby/3.1/lib/ruby/gems/3.1.0/gems/activerecord-7.0.3/lib/active_record/connection_adapters/abstract/database_statements.rb:531:in 'with_multi_statements'

#after
from /opt/ruby/3.1/lib/ruby/gems/3.1.0/gems/activerecord-7.0.3/lib/active_record/connection_adapters/abstract/database_statements.rb:531:in 'ActiveRecord::ConnectionAdapters::DatabaseStatements#with_multi_statements'

Much less beautiful than the (contrived) example, imho.

Note: I'm not sure if the above would display the module where the method is defined (ActiveRecord::ConnectionAdapters::DatabaseStatements) or the class where the module is included.

Updated by byroot (Jean Boussier) 10 months ago

Please try it with a Rails backtrace, so you get something like:

@Dan0042 (Daniel DeLorme) I find that is much better than the existing backtrace. ¯\_(ツ)_/¯

I mean, we're including more information, so yes it's longer, but in your example it's the file location that is causing the line to be too long. You are already at 163 characters, including 131 for the path itself.

Updated by Dan0042 (Daniel DeLorme) 10 months ago

It's not so much the length but the redundancy. "active_record/connection_adapters/abstract/database_statements" is repeated as "ActiveRecord::ConnectionAdapters::DatabaseStatements"

It's hard for me to say if I would like the feature or not, without seeing a full Rails backtrace. Just one line gives a certain (imho bad) foretaste, but not enough for a clear opinion. And at least the test.rb example certainly looked better.

Updated by byroot (Jean Boussier) 10 months ago

"connection_adapters/abstract/database_statements" is repeated as "ActiveRecord::ConnectionAdapters::DatabaseStatements"

That is the case in the example you chose, but is absolutely not a given.

Can you tell me without opening the source file, the owner of that method? (I took an example Active Record to be close to your example):

/Users/byroot/.gem/ruby/3.2.2/gems/activerecord-7.1.2/lib/active_record/connection_adapters/abstract/connection_pool.rb:30:in `checkin': wrong number of arguments (given 0, expected 1) (ArgumentError)

Updated by Dan0042 (Daniel DeLorme) 10 months ago

byroot (Jean Boussier) wrote in #note-32:

Can you tell me without opening the source file, the owner of that method?

Normally it would be ActiveRecord::ConnectionAdapters::ConnectionPool; now I'm sure you chose an example where that is not the case, but I think 90-95% of the time you can infer the classname from the filename. That's just how Ruby code is written nowadays. So it's not "absolutely" a given, but it's very close to a given.

Updated by byroot (Jean Boussier) 10 months ago

That's just how Ruby code is written nowadays.

It's a common pattern for classes that are long enough, but it's also very common to cram multiple smaller classes in the same file, or multiple classes that are alternative implementations of the same interface.

The pattern is very common in Rails project because the autoloader forces you into a convention, but in gems or non-rails projects, anything goes.

And even in Rails projects, it's common not to extra small sub constants in their own file:

# user.rb
class User
  class Permission
    # a dozen lines, not worth creating `user/permission.rb`
  end
end

And that also include numerous methods from the Ruby standard libraries, e.g.: shellwords

>> foo.shelljoin(1)
/Users/byroot/.rbenv/versions/3.3.0/lib/ruby/3.3.0/shellwords.rb:239:in `shelljoin': wrong number of arguments (given 1, expected 0) (ArgumentError)

Good luck guessing what shelljoin was called on.

With this patch it would be:

>> foo.shelljoin(1)
/Users/byroot/.rbenv/versions/3.3.0/lib/ruby/3.3.0/shellwords.rb:239:in `Array#shelljoin': wrong number of arguments (given 1, expected 0) (ArgumentError)

In other words, the Class#method pattern make it super easy to lookup the documentation, the path and line number, not so much. Personally I spend half my time opening the source of my dependencies, but for less confirmed users, opening the stdlib to read the source isn't a nice value proposition.

Updated by mame (Yusuke Endoh) 10 months ago

In fact, I am also a bit afraid that it could be too redundant in large-scale app development. But it's interesting that byroot, who is far more familiar with large-scale app development than me, thinks that it's useful.

It is hard to evaluate this kind of UI in the mind. We need to use it.
Before the introduction of error_highlight, there was an opinion that "there is no need to display information that can be easily understood by just opening the source code." However, it awfully improved the developer experience (at least for me).

I am a little concerned about compatibility. But if we change the backtick to a single quote (#16495), I would like to do it incidentally.

I would like @matz (Yukihiro Matsumoto) to make the final decision on whether or not to try this change.

Updated by byroot (Jean Boussier) 10 months ago

large-scale app development

Yes, the larger the app, the more likely you are to have many methods with the same name in different modules / classes, and the more gems with different file naming conventions.

It is hard to evaluate this kind of UI in the mind. We need to use it.

Agreed. I'm for trying it early in the 3.4 cycle, if we get negative feedback from the community that tries the previews / rcs, we can always change it back before release.

Also it's likely (still not 100% decided) we'll be running a 3.4 prerelease sometime around March or April on our monolith, so we can get feedback from hundreds of developers long before the final release.

Updated by Dan0042 (Daniel DeLorme) 10 months ago

byroot (Jean Boussier) wrote in #note-36:

Also it's likely (still not 100% decided) we'll be running a 3.4 prerelease sometime around March or April on our monolith, so we can get feedback from hundreds of developers long before the final release.

Oh, that's very nice. I'm looking forward to hear the feedback from actual usage.

Updated by ko1 (Koichi Sasada) 9 months ago

Do we need quotes?

From comment #28

./test.rb:10:in `Integer#+': String can't be coerced into Integer (TypeError)
	from ./test.rb:10:in `block in Concrete.oops'
	from ./test.rb:3:in `Abstract#oops'
	from ./test.rb:16:in `block in Concrete#oops'
	from <internal:kernel>:90:in `Kernel#tap'
	from ./test.rb:15:in `Concrete#oops'
	from ./test.rb:10:in `Concrete.oops'
	from ./test.rb:21:in `Method#call'
	from ./test.rb:21:in `<main>'

vs

./test.rb:10:in Integer#+: String can't be coerced into Integer (TypeError)
	from ./test.rb:10:in block in Concrete.oops
	from ./test.rb:3:in Abstract#oops
	from ./test.rb:16:in block in Concrete#oops
	from <internal:kernel>:90:in Kernel#tap
	from ./test.rb:15:in Concrete#oops
	from ./test.rb:10:in Concrete.oops
	from ./test.rb:21:in Method#call
	from ./test.rb:21:in <main>

For example, python's case;

$ python3
Python 3.10.12 (main, Nov 20 2023, 15:14:05) [GCC 11.4.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> def foo(a):
...     a + 10
...
>>> foo("str")
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "<stdin>", line 2, in foo
TypeError: can only concatenate str (not "int") to str

Updated by byroot (Jean Boussier) 9 months ago

Do we need quotes?

I'm not attached to them, and I suppose removing them would also solve https://bugs.ruby-lang.org/issues/16495 / https://bugs.ruby-lang.org/issues/17107.

Updated by Eregon (Benoit Daloze) 9 months ago

I think without quotes, while it looks clean for a simple example of all short paths it can be slower/harder to find the method name with more realistic cases.
For example in the case in https://bugs.ruby-lang.org/issues/19117#note-32, it would be:

/Users/byroot/.gem/ruby/3.2.2/gems/activerecord-7.1.2/lib/active_record/connection_adapters/abstract/connection_pool.rb:30:in checkin: wrong number of arguments (given 0, expected 1) (ArgumentError)

If the exception message contains : then it becomes quite hard to scan too.

Updated by ko1 (Koichi Sasada) 9 months ago

It should be:

/Users/byroot/.gem/ruby/3.2.2/gems/activerecord-7.1.2/lib/active_record/connection_adapters/abstract/connection_pool.rb:30:in ActiveRecord::Foo::Bar#checkin: wrong number of arguments (given 0, expected 1) (ArgumentError)

(I'm not sure the correct class name...)

I meant that it may be easy to find method names by adding class name without using quotation marks.

Updated by Eregon (Benoit Daloze) 9 months ago

Oops, indeed.
It seems a bit easier to me to read with the quotes:

/Users/byroot/.gem/ruby/3.2.2/gems/activerecord-7.1.2/lib/active_record/connection_adapters/abstract/connection_pool.rb:30:in 'ActiveRecord::Foo::Bar#checkin': wrong number of arguments (given 0, expected 1) (ArgumentError)

Also the from ./test.rb:16:in block in Concrete#oops above seems clearer with quotes:
from ./test.rb:16:in 'block in Concrete#oops'

I was searching for a long backtrace mixing many filenames/paths of different length but didn't find one at hand.
That could be good to get a clearer idea of what's more readable (although obviously some of it is subjective).

Updated by matz (Yukihiro Matsumoto) 9 months ago

I am OK with adding method owner. I am against removing quote signs.

Matz.

Actions #44

Updated by mame (Yusuke Endoh) 9 months ago

  • Status changed from Open to Closed

Applied in changeset git|61819c87b29f3267d6a2499d9018f09cd5bcf2c4.


Let Thread::Backtrace::Location have a method entry

Instead of having iseq and cfunc separately, this change lets
Thread::Backtrace::Location have them together as
rb_callable_method_entry_t.

This is a refactoring, but also a preparation for implementing
[Feature #19117].

Updated by byroot (Jean Boussier) 9 months ago

@mame (Yusuke Endoh) while updating the Rails test suite I noticed we may have a small regression:

def raise_nested_exceptions
  raise "First error"
rescue
  begin
    raise "Second error"
  rescue
    raise "Third error"
  end
end

raise_nested_exceptions

3.3.0:

/tmp/foo.rb:7:in `rescue in rescue in raise_nested_exceptions': Third error (RuntimeError)
	from /tmp/foo.rb:4:in `rescue in raise_nested_exceptions'
	from /tmp/foo.rb:1:in `raise_nested_exceptions'
	from /tmp/foo.rb:11:in `<main>'
/tmp/foo.rb:5:in `rescue in raise_nested_exceptions': Second error (RuntimeError)
	from /tmp/foo.rb:1:in `raise_nested_exceptions'
	from /tmp/foo.rb:11:in `<main>'
/tmp/foo.rb:2:in `raise_nested_exceptions': First error (RuntimeError)
	from /tmp/foo.rb:11:in `<main>'

3.4-dev:

/tmp/foo.rb:7:in 'Object#raise_nested_exceptions': Third error (RuntimeError)
	from /tmp/foo.rb:4:in 'Object#raise_nested_exceptions'
	from /tmp/foo.rb:1:in 'Object#raise_nested_exceptions'
	from /tmp/foo.rb:11:in '<main>'
/tmp/foo.rb:5:in 'Object#raise_nested_exceptions': Second error (RuntimeError)
	from /tmp/foo.rb:1:in 'Object#raise_nested_exceptions'
	from /tmp/foo.rb:11:in '<main>'
/tmp/foo.rb:2:in 'Object#raise_nested_exceptions': First error (RuntimeError)
	from /tmp/foo.rb:11:in '<main>'

The rescue in prefixes are gone. I don't think it was intended?

Updated by mame (Yusuke Endoh) 9 months ago

You've been found out!

During this work, I noticed a problem with the inconsistency of ensure in.

begin
ensure
  p caller(0) #=> ["test.rb:3:in `<main>'"]
end

begin
  raise
ensure
  p caller(0) #=> ["test.rb:9:in `ensure in <main>'", "test.rb:9:in `<main>'"]
end

If it enters into the ensure clause with an exception, you will see ensure in. But if it enters normally (without an exception), you will not see ensure in. This depends on the implementation details of ensure in RubyVM.

I discussed this with @ko1 (Koichi Sasada), and we decided to remove ensure in (and rescue in as well).

So I removed it intentionally and hoped no one noticed it :-P
I can probably restore rescue in and ensure in with the above inconsistency. Do you like it?

Updated by byroot (Jean Boussier) 9 months ago

I can probably restore rescue in and ensure in with the above inconsistency. Do you like it?

I honestly don't mind either way, I noticed this while updating the Rails test suite, figured I'd report it in case it wasn't intentional.

I suppose you could argue that rescue in has some value, as it shows there was some error handling, but I'm not particularly attached to it. I'm totally fine with removing it.

Updated by Eregon (Benoit Daloze) 9 months ago

I'm in favor to keep it removed, because these are implementation details.
Although ideally in backtraces I think it would be best to hide the entry corresponding to rescue in/ensure in, i.e., instead of:

/tmp/foo.rb:7:in `rescue in rescue in raise_nested_exceptions': Third error (RuntimeError)
	from /tmp/foo.rb:4:in `rescue in raise_nested_exceptions'
	from /tmp/foo.rb:1:in `raise_nested_exceptions'
	from /tmp/foo.rb:11:in `<main>'

have:

/tmp/foo.rb:7:in 'Object#raise_nested_exceptions': Third error (RuntimeError)
	from /tmp/foo.rb:11:in '<main>'

Since there are no calls from Ruby semantics POV and the extra frames are a CRuby implementation detail (e.g. TruffleRuby does not have extra call frames for rescue and ensure, not sure about JRuby).

Updated by Dan0042 (Daniel DeLorme) 9 months ago

If "rescue in" is removed, then what happens to the similar "block in" ?

Also in terms of quotes, what are your thoughts on
from ./test.rb:16:in 'block in Concrete#oops'
vs
from ./test.rb:16:in block in 'Concrete#oops'

Updated by mame (Yusuke Endoh) 9 months ago

No one seems to want to treat rescue in and ensure in as a regression.

I think that we should discuss further improvements in a separate ticket.

Updated by Eregon (Benoit Daloze) 9 months ago

@Dan0042 (Daniel DeLorme) I think block in should stay because those must be calls and have their own frame semantically.

The quotes are around the block in (on master), which makes sense because that's the name of the "thing being called".
I.e. the block is being called, the surrounding method might not be on the stack at all, e.g.:

$ ruby -e 'def m = proc { raise }; m.call'
-e:1:in 'block in Object#m': unhandled exception
	from -e:1:in '<main>'
Actions #52

Updated by Eregon (Benoit Daloze) 9 months ago

  • Related to Feature #20275: Avoid extra backtrace entries for rescue and ensure added

Updated by Eregon (Benoit Daloze) 9 months ago

I think that we should discuss further improvements in a separate ticket.

OK: #20275

Updated by Eregon (Benoit Daloze) 8 months ago · Edited

  • Assignee set to Eregon (Benoit Daloze)

Updated by Eregon (Benoit Daloze) 8 months ago

  • Assignee changed from Eregon (Benoit Daloze) to mame (Yusuke Endoh)
Actions

Also available in: Atom PDF

Like7
Like0Like0Like0Like1Like0Like0Like0Like0Like0Like0Like0Like1Like0Like0Like0Like0Like0Like0Like0Like0Like1Like1Like1Like0Like0Like1Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like1Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0