Project

General

Profile

Actions

Feature #18285

closed

NoMethodError#message uses a lot of CPU/is really expensive to call

Added by ivoanjo (Ivo Anjo) over 2 years ago. Updated 2 months ago.

Status:
Closed
Assignee:
-
Target version:
-
[ruby-core:105909]

Description

Hello there! I'm working at Datadog on the ddtrace gem -- https://github.com/DataDog/dd-trace-rb and we ran into this issue on one of our internal testing applications. I also blogged about this issue in https://ivoanjo.me/blog/2021/11/01/nomethoderror-ruby-cost/.

Background

While testing an application that threw a lot of NoMethodErrors in a Rails controller (this was used for validation), we discovered that service performance was very much impacted when we were logging these exceptions. While investigating with a profiler, the performance impact was caused by calls to NoMethodError#message, because this Rails controller had a quite complex #inspect method, that was getting called every time we tried to get the #message from the exception.

How to reproduce

require 'bundler/inline'

gemfile do
  source 'https://rubygems.org'

  gem 'benchmark-ips'
end

puts RUBY_DESCRIPTION

class GemInformation
  # ...

  def get_no_method_error
    method_does_not_exist
  rescue => e
    e
  end

  def get_runtime_error
    raise 'Another Error'
  rescue => e
    e
  end

  def inspect # <-- expensive method gets called when calling NoMethodError#message
    Gem::Specification._all.inspect
  end
end

NO_METHOD_ERROR_INSTANCE = GemInformation.new.get_no_method_error
RUNTIME_ERROR_INSTANCE = GemInformation.new.get_runtime_error

Benchmark.ips do |x|
  x.config(:time => 5, :warmup => 2)

  x.report("no method error message cost") { NO_METHOD_ERROR_INSTANCE.message }
  x.report("runtime error message cost") { RUNTIME_ERROR_INSTANCE.message }

  x.compare!
end

Expectation and result

Getting the #message from a NoMethodError should be no costly than getting it from any other exception.

In reality:

ruby 3.0.2p107 (2021-07-07 revision 0db68f0233) [x86_64-linux]

no method error message cost
                        115.390  (± 1.7%) i/s -    580.000  in   5.027822s
runtime error message cost
                          6.938M (± 0.5%) i/s -     35.334M in   5.092617s

Comparison:
runtime error message cost:  6938381.6 i/s
no method error message cost:      115.4 i/s - 60130.02x  (± 0.00) slower

Suggested solutions

  1. Do not call #inspect on the object on which the method was not found (see https://github.com/ruby/ruby/blob/e0915ba67964d843832148aeca29a1f8244ca7b1/error.c#L1962)
  2. Cache result of calling #message after the first call. Ideally this should be done together with suggestion 1.

Related issues 7 (3 open4 closed)

Related to Ruby master - Feature #6733: New inspect frameworkOpenActions
Related to Ruby master - Bug #6291: Backtrace printout halts for an extremely long time when large amounts of data are allocatedClosedmatz (Yukihiro Matsumoto)04/14/2012Actions
Related to Ruby master - Feature #6783: Infinite loop in inspect, not overriding inspect, to_s, and no known circular references. Stepping into inspect in debugger locks it up with 100% CPU.OpenActions
Related to Ruby master - Feature #19520: Support for `Module.new(name)` and `Class.new(superclass, name)`.RejectedActions
Has duplicate Ruby master - Bug #19065: ruby 3.1.2 is printing all class variables for undefined errorClosedActions
Has duplicate Ruby master - Feature #19978: NoMethodError and large objects should not create unwieldy error messagesClosedActions
Is duplicate of Ruby master - Feature #9725: Do not inspect NameError target object unless verboseOpenActions
Actions #1

Updated by ivoanjo (Ivo Anjo) over 2 years ago

  • Description updated (diff)

Updated by Eregon (Benoit Daloze) over 2 years ago

I think we've had this report multiple times, it's a trade-off between efficiency and useful information being shown.
Ideally #inspect wouldn't be so expensive.

NoMethodError is typically because the method isn't defined on the class of that instance, and very rarely because it's not defined on the singleton class of that instance (except if it's a Module/Class).
Hence showing data of that specific instance seems not so valuable, might as well just show the class.

So I think one good fix here would be to use the basic Kernel#to_s to format the receiver, i.e., rb_any_to_s() and with special handling for true/false/nil, and also for modules (show the module name).
Then we wouldn't lose too much information from the exception (the class of the object would still be obvious) and avoid the drawbacks.

Updated by ivoanjo (Ivo Anjo) over 2 years ago

Yeah, I think it's useful to include the object class and possibly its id, but with the default #inspect behavior of "print the object and all of its instance variables, and do it recursively", it's a rather sharp edge to have it being called when getting the exception message here.

Updated by byroot (Jean Boussier) over 2 years ago

If applicable, I suggest to do what we do in Rails: https://github.com/rails/rails/blob/f95c0b7e96eb36bc3efc0c5beffbb9e84ea664e4/activesupport/lib/active_support/core_ext/name_error.rb#L13-L18

When dealing with NameError and its subclasses, first check for original_message.

Updated by mame (Yusuke Endoh) over 2 years ago

we ran into this issue on one of our internal testing applications.

Let me confirm: you are facing this issue when testing dd-trace-rb, not in production, right? I cannot imagine how NameError#message is called so many times in production.

If this is the case only when testing, how about adding a manual cache mechanism into the test suite of dd-trace-rb? I think this is almost the same as what you are proposing in this ticket at the Ruby level.

module CacheMessage
  def message
    @__message ||= super
  end
end
NameError.prepend(CacheMessage)

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

If applicable, I suggest to do what we do in Rails:

In this case, the main overhead is due to receiver#inspect that returns a long string, not due to did_you_mean (and error_highlight). Actually I can see no significant improvement by running the given benchmark script with --disable-did_you_mean.

Updated by ivoanjo (Ivo Anjo) over 2 years ago

Important note! I'm actually talking about NoMethodError, not NameError, so I don't think this issue is caused by the did you mean gem behavior (which I really like).

This may have been confusing because both of them share the NameError::message class where the actual call to #inspect lives.

Let me confirm: you are facing this issue when testing dd-trace-rb, not in production, right? I cannot imagine how NameError#message is called so many times in production.

Apologies for the confusion. I meant that we were simulating what if a production Rails application had a bug (in this case, mistakenly called a method that had been deleted), and how dd-trace-rb would help customers debug such an issue.

I think it's reasonable assertion to say this can happen -- people will do these kinds of mistakes, and if they're not paying attention to their logs/alarms/error tracking data, their app can be impacted by such an issue for a while until they realize what's going on and have the chance to deploy a fix.


In my view, part of the problem here is that on classes with a big #inspect, the call to #inspect ends up being completely useless on Ruby 2.7 and below:

> puts RUBY_DESCRIPTION
ruby 2.7.4p191 (2021-07-07 revision a21a3b7d23) [x86_64-darwin19]
> class Foo; def inspect; puts 'inspect called!'; 'A' * 65; end; end
> Foo.new.foo
inspect called!
# => NoMethodError: undefined method `foo' for AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA:Foo
> class Foo; def inspect; puts 'inspect called!'; 'A' * 66; end; end
> Foo.new.foo
inspect called!
# => NoMethodError: undefined method `foo' for #<Foo:0x00007f875719b140>

When I was testing, I wasn't seeing the result of the #inspect, so it wasn't even occurring to me what was going on (and this is what confused me even further).

I realize now that the limit was removed in 3.0 (https://bugs.ruby-lang.org/issues/16832 and https://github.com/ruby/ruby/pull/3090) so in 3.0 it always shows the whole string, which can be a whole another problem as well, because people may not be expecting a NoMethodError to contain a small novel in its #message.

So what I'm asking upstream to consider is:

Could we simplify NoMethodError to not include the #inspect? According to the PR above, the previous limit was in place for about 24 years and it looks like nobody really complained that they couldn't see their #inspect on objects which had a complex one.

Updated by byroot (Jean Boussier) over 2 years ago

I'm actually talking about NoMethodError, not NameError, so I don't think this issue is caused by the did you mean gem behavior

No the confusion is mine, I assumed it was a did_you_mean perf issue without fully digging into your repro because I ran into those previously.

Could we simplify NoMethodError to not include the #inspect?

I'm personally not against it, e.g:

>> {foo: 42}.bar
(irb):2:in `<main>': undefined method `bar' for {:foo=>42}:Hash (NoMethodError)

The content of the hash here isn't really helpful, in the context of a NoMethodError all I really care about is the type of the object, so why not. I might be missing some use cases though.

the previous limit was in place for about 24 years and it looks like nobody really complained that they couldn't see their #inspect on objects which had a complex one.

Well I for one complained about that limit, hence why I opened the ticket.

Also note that the limit would still have called #inspect, just not used the result, so unless I'm missing something, you could truncate Error#message yourself and have roughly the same performance.

And in the context of a library reporting error, you might have to deal with arbitrary errors raised by the application code, so you can't assume all errors will have a reasonably small message anyway.

Updated by ivoanjo (Ivo Anjo) over 2 years ago

Well I for one complained about that limit, hence why I opened the ticket.

Right! Thanks for pointing it out.

Also note that the limit would still have called #inspect, just not used the result, so unless I'm missing something, you could truncate Error#message yourself and have roughly the same performance.

Good point. What I meant was that for a long time it seemed OK to not get the #inspect information some of the time, so I was trying to use that to make a case that perhaps the default should not be to use #inspect, not to use the inspect always :)

One additional note is that if one needs it, it's possible to get the #inspect information because the exception exposes the reference to the original object:

[1] pry(main)> exception = begin; "hello".foo; rescue => e; e; end
=> #<NoMethodError: undefined method `foo' for "hello":String>
[3] pry(main)> exception.receiver
=> "hello"
[4] pry(main)> exception.receiver.inspect
=> "\"hello\""

Updated by byroot (Jean Boussier) over 2 years ago

I was trying to use that to make a case that perhaps the default should not be to use #inspect, not to use the inspect always :)

Not sure if I got you right, but in my opinion the old behavior of only using it if it was smaller than 65 chars long was quite horrible and confusing, so I don't think simply going back to this is a good idea.

Again, I can get behind the idea of not including receiver.inspect in NoMethodError#message, but the question now is what to include exactly? The class with some special casing for true/false/nil like @Eregon (Benoit Daloze) suggested?

What about arrays, strings, hash etc? Is there any point including their representation?

Updated by ivoanjo (Ivo Anjo) over 2 years ago

My suggestion is indeed to only include the class + perhaps the pointer id or the object id for regular user classes, and then special case true/false/nil and perhaps String and symbols.

Updated by Eregon (Benoit Daloze) over 2 years ago

Re special casing, true/false/nil are typically already special-cased for exception messages (because #<TrueClass:0x0000000000000014> is too confusing, everyone expects true or true:TrueClass, which is BTW the current formatting: undefined method 'foo' for true:TrueClass (NoMethodError)).
So it's like Kernel.instance_method(:to_s).bind_call(receiver), except for true/false/nil, and except for modules, where we get the name (String instead of #<Class:0x000000000246a828>).
I would not special-case anything else, the smaller that list the better. The only reason to special case true/false/nil/Module is because otherwise it's too confusing.
(Showing a String's contents is a good counter example, it can be really long and is not useful for a NoMethodError)

Code is likely clearer:

# Already the case, nothing to change for those :)
true.foo  # => undefined method `foo' for true:TrueClass (NoMethodError)
false.foo # => undefined method `foo' for false:FalseClass (NoMethodError)
nil.foo   # => undefined method `foo' for nil:NilClass (NoMethodError)
Object.new.foo # => undefined method `foo' for #<Object:0x0000000002f3afc8> (NoMethodError)
String.foo # => undefined method `foo' for String:Class (NoMethodError)

# Suggested change:
"foobar".foo
# old => undefined method `foo' for "foobar":String (NoMethodError)
# new => undefined method `foo' for #<String:0x0000000002ffaaa8> (NoMethodError)
(the String could be very long, same for other object with long or expensive #inspect)

Object.new.instance_exec { @a = 42; self.foo }
# old => undefined method `foo' for #<Object:0x00000000025e6030 @a=42> (NoMethodError)
# new => undefined method `foo' for #<Object:0x00000000025e6030> (NoMethodError)
(printing ivars could lead to very long and slow output due to recursive #inspect)

Updated by ivoanjo (Ivo Anjo) over 2 years ago

Thanks Benoit for stating in very clear and exact terms what I was trying to express :)

Actions #13

Updated by mame (Yusuke Endoh) over 2 years ago

Updated by mame (Yusuke Endoh) over 2 years ago

@matz (Yukihiro Matsumoto) and @naruse (Yui NARUSE) said let's try any_to_s approach after Ruby 3.1 is released, towards Ruby 3.2.

We need to handle some basic classes specially rather than true/false/nil. @akr (Akira Tanaka) pointed showing #<Class:0xXXXXXXXXXXXXXXXX> for a class is rather confusing.

class Foo
  privatee
end

#=> current:  undefined local variable or method `privvate' for Foo:Class (NameError)
#=> proposal: undefined local variable or method `privvate' for #<Class:0xXXXXXXXXXXXXXXXX> (NameError)

Also, @nobu (Nobuyoshi Nakada) said #<Integer:0xXXXXXXXXXXXXXXXX> would be annoying. Maybe we need to use the new behavior actually for a while, feel how stressful it is, and adjust the representation.

Updated by duerst (Martin Dürst) over 2 years ago

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

#=> current: undefined local variable or method privvate' for Foo:Class (NameError) #=> proposal: undefined local variable or method privvate' for #Class:0xXXXXXXXXXXXXXXXX (NameError)


Also, @nobu said `#<Integer:0xXXXXXXXXXXXXXXXX>` would be annoying. Maybe we need to use the new behavior actually for a while, feel how stressful it is, and adjust the representation.

I'm very sure we do not need a trial period to know that #<Class:0xXXXXXXXXXXXXXXXX> or #<Integer:0xXXXXXXXXXXXXXXXX> are a bad idea. The trial period may be needed to find all the other cases.

Updated by Eregon (Benoit Daloze) over 2 years ago

I think #<Integer:0xXXXXXXXXXXXXXXXX> is actually not really problematic in this context, because the missing method is a method not defined on the Integer class (or above), so the useful information is there.
But I agree it's confusing/unfamiliar output.

Maybe we should call #inspect if it's a "basic=core & not redefined" method, except for Kernel#inspect, or just hardcode key core classes.
Or another way to say it is it's fine to call a known #inspect if it doesn't recurse and print other objects.

We should use Module#inspect/name, that was already said in https://bugs.ruby-lang.org/issues/18285#note-11.
modules can and often have a singleton class, so there it is important to show instance-specific information.
Modules are already a special case in name error message IIRC.

Actions #17

Updated by Eregon (Benoit Daloze) over 2 years ago

  • Related to Bug #6291: Backtrace printout halts for an extremely long time when large amounts of data are allocated added
Actions #18

Updated by Eregon (Benoit Daloze) over 2 years ago

  • Related to Feature #6783: Infinite loop in inspect, not overriding inspect, to_s, and no known circular references. Stepping into inspect in debugger locks it up with 100% CPU. added

Updated by Dan0042 (Daniel DeLorme) over 2 years ago

The simplifications are all super good ideas, but I'd like to know why no one seems to be considering suggestion #2 "Cache result of calling #message after the first call."
Memoizing the message seems a very low-hanging fruit for performance improvement.

the previous limit was in place for about 24 years and it looks like nobody really complained that they couldn't see their #inspect on objects which had a complex one.

Well I for one complained about that limit, hence why I opened the ticket.

But #16832 was about having a meaningful error message for missing constants. No one considered having a megabyte-sized message because of a NoMethodError on megabyte-sized strings. I think this is a bug in 3.0 that should be fixed and backported.

Updated by mame (Yusuke Endoh) about 2 years ago

  • Tracker changed from Misc to Feature

Discussed at the dev-meeting but no conclusion.

@akr (Akira Tanaka) said the part 0xXXXXXXXXXXXXXXXX is almost useless, and roughly counter-proposed the following.

42.time    #=> undefined method `time' for object Integer (NoMethodError)

class Foo
  privatee #=> undefined local variable or method 'privatee' for class Foo (NoMethodError)
end

def (o=Object.new).foo
end
o.bar      #=> undefined method `bar' for extended object Object (NoMethodError)

The phrase object Foo might be improved to, say, an instance of Foo.

Updated by Dan0042 (Daniel DeLorme) about 2 years ago

"undefined method 'time' for object Integer" is grammatically incorrect.
It would need to be "undefined method 'time' for Integer object".
Or "instance of Integer" or "object of type Integer".

Updated by Eregon (Benoit Daloze) about 2 years ago

I think Ruby users already know well what #<MyObject:0xXXXXXXXXXXXXXXXX> means, and using another naming is likely more confusing.
Either way it will need some getting used to as it's new output, and then it will just be natural.
There are already places using rb_any_to_s() (e.g., when inspect/to_s don't return a String, etc) and this would just be another.

That said, for MyObject instance/for module Foo/for class Bar seems fine and simple enough if that's deemed better.
"Integer object" or so seems confusing, so the instance terminology seems better.

Actions #23

Updated by mame (Yusuke Endoh) over 1 year ago

  • Has duplicate Bug #19065: ruby 3.1.2 is printing all class variables for undefined error added

Updated by ivoanjo (Ivo Anjo) over 1 year ago

Hey everyone! I actually had someone reach out to me (because I had blogged about this) the other day, since they had been bitten by this issue.

Interestingly, it appears that actually this keeps getting "rediscovered" in the Ruby ecosystem. Here's a Rails ticket from 2011 -- https://github.com/rails/rails/issues/1525 -- and looking at the "mentioned this issue" backlinks at the bottom, some gems and apps are even getting workarounds on their inspect to avoid causing issues. Here's one example: https://github.com/alphagov/whitehall/blob/main/config/initializers/small_inspect.rb .

Updated by mame (Yusuke Endoh) over 1 year ago

I have created a PR based on @akr (Akira Tanaka) 's proposal.

https://github.com/ruby/ruby/pull/6950

42.time    #=> undefined method `time' for object Integer (NoMethodError)

class Foo
  privatee #=> undefined local variable or method 'privatee' for class Foo (NoMethodError)
end

s = ""
def s.foo = nil
s.bar      #=> undefined method `bar' for extended object String (NoMethodError)

I think we can almost agree to stop using #inspect in NoMethodError#message.
Now, we need to decide the new message format.

However, I think it is difficult to decide this through discussion and imagination because it is very much a matter of preference.

So, how about trying @akr's proposal towards Ruby 3.3, after the release of Ruby 3.2?
Let's evaluate how annoying (or not) the new error format would be for daily programming by those who uses master.

Note that @akr (Akira Tanaka) is one of the most proven and trusted committers in the area of designing Ruby.
I believe that his proposal is a good start.

Updated by zverok (Victor Shepelev) about 1 year ago

I understand I am late to the party, but I am extremely concerned with how the discussion in this ticket went.

From my understanding:

  1. There are many contexts, especially with designing, experimenting, and prototyping with Ruby, where "what object the problem happened with" frequently saves minutes, if not hours, of head-scratching (I give one trivial example below)
  2. #inspect is a method that is dedicated to reasonable introspection and helping debugging; I believe it kinda implies that the user classes are advised to implement it in an efficient way, so it would be cheap to embed it into diagnostics
  3. As far as I understand, the problem originates in Rails, which (as they do) doesn't try to follow good practices for #inspect (which is honestly frequently irritating)
  4. So, by solving the Rails problem, we are making the life of all Rubyists worse?..

Why I believe it would be worse—in response to:

NoMethodError is typically because the method isn't defined on the class of that instance, and very rarely because it's not defined on the singleton class of that instance (except if it's a Module/Class). Hence showing data of that specific instance seems not so valuable, might as well just show the class. (@Eregon (Benoit Daloze))

The content of the hash here isn't really helpful, in the context of a NoMethodError all I really care about is the type of the object, so why not. (@byroot (Jean Boussier))

Those statements are relevant for typo-originated NoMethodError accidents (like some_hash.deelte), but not as relevant for duck/dynamic-typing originated ones.

Say, in a complicated algorithm working with nested data structures, undefined method transform_keys for object Array is significantly worse than undefined method transform_keys for [{id: 1, name: 'John'}]. Or, undefined method punctuation? for TokenGroup is worse than undefined method punctuation? for [Token['def'] Token['end']]:TokenGroup

The latter indicates immediately which piece of data defies the initial assumption about the structure (some users: are passed as an array, maybe after API version change; some particular fragment of parsed data produced a group of tokens where a singular token was expected), the former requires starting debugging and printing intermediate values.

Honestly, I would much rather prefer users to be advised "make sure your #inspect is efficient" than make everybody suffer.

PS: The problem of too-long error messages is also interesting—but I don't believe that "just never use #inspect is a good solution for it either.

Updated by byroot (Jean Boussier) about 1 year ago

As far as I understand, the problem originates in Rails, which (as they do) doesn't try to follow good practices for #inspect (which is honestly frequently irritating)

This absolutely isn't specific to Rails. It can happen with any object that has a large number of reference.

Try your transform_keys example on a large API payload you received and you'll produce a gigantic error message.

"People are holding it wrong" isn't a proper way to address issues.

Updated by zverok (Victor Shepelev) about 1 year ago

@byroot (Jean Boussier) I am not denying the problem exists or saying it shouldn't be handled (and I acknowledge my Rails remark was inappropriate).

I am just saying that the way of fixing it by replacing the object representation with class name breaks many good use cases and, in general, seems less friendly to me.
It always felt nice and informative.

Interesting to note that the latest Ruby releases tend to add more context for errors (with did_you_mean and error_highlight), and it is considered a good thing, while this change seems to go in the exactly opposite direction.

Actually, thinking a bit more about this, maybe a good compromise solution would be to preserve this change but add #inspect of the object to NoMethodError#detailed_message?.. It seems to be introduced exactly to handle the balance between the efficiency/brevity of the "core" message and helpfulness.

As for the problems which #inspect in (any) error message leads to, I believe there are two related but different ones?

  1. What if #inspect output is too long? Intuitively, I would say that there are many techniques of mechanical shortening of the string to the desired limit. Say, modern IRB handles it quite gracefully (this is a copy-paste of FULL IRB session, the ... is what it did):
>> ary = [{a: 1, foo: :bar}] * 100
=> 
[{:a=>1, :foo=>:bar},                                                              
...                           
  1. What if #inspect is very inefficient? In this case a) actually, yes, I believe that it is client's code responsibility (and it is not "sharp knife"-class responsibility, it is rather "if you've implemented to_s to return a number, nothing would work properly"), but b) maybe the detailed_message idea helps mitigating this, anyway?..

Updated by byroot (Jean Boussier) about 1 year ago

What if #inspect is very inefficient? In this case a) actually, yes, I believe that it is client's code responsibility

Note that in the example provided in the original issue, the slow #inspect is simply the default Object#inspect.

The vast majority of classes out there don't define a custom inspect. So Ruby should do something reasonable for these cases.

Updated by byroot (Jean Boussier) about 1 year ago

Note that in the example provided in the original issue

I just realized my response was confusing. To clarify I meant ActionController::Base#inspect. Which resolve to Object#inspect. Controllers simply are the root of a very large object graph.

Updated by zverok (Victor Shepelev) about 1 year ago

The vast majority of classes out there don't define a custom inspect. So Ruby should do something reasonable for these cases.

That's true.

(I still maintain that it could/should be a good community practice to define better #inspects for better debuggability, because eventual p self in pry session of a controller is painful as well, but that's a different question.)

Updated by ivoanjo (Ivo Anjo) about 1 year ago

The vast majority of classes out there don't define a custom inspect. So Ruby should do something reasonable for these cases.

+1 My intention with my bug report was to call this out -- inspect can get really expensive, and you just need a complex object graph where every object uses the default inspect to cause that.

And in my very humble opinion this is fine, because the way I've always seen it is that #inspect is supposed to be something that gets used while debugging, not in production. E.g. my base assumption is: in production the common case is that #inspect is never called. (Unless some production debugging tool is using it explicitly)

The footgun happens when #inspect is combined with NoMethodError, which is definitely something that can happen in production, and can be triggered by both typos as well as (as pointed out above) duck/dynamic-typing bugs.

I like @mame (Yusuke Endoh) 's PR since it avoids this issue in the default case, thus locking away the footgun. And it creates a new question -- how to get at this useful information while debugging?

@zverok (Victor Shepelev) 's idea of using NoMethodError#detailed_message seems interesting when combined with https://github.com/ruby/ruby/pull/6950. Maybe some kind of combination is an interesting answer for this issue?

Updated by Eregon (Benoit Daloze) about 1 year ago

zverok (Victor Shepelev) wrote in #note-26:

Honestly, I would much rather prefer users to be advised "make sure your #inspect is efficient" than make everybody suffer.

That's not reasonable to ask. #inspect was never meant to be efficient but to provide maximum debugging information.
It's simply too expensive to call for a large object graph for an exception message (even with no one redefining inspect).
If the receiver is known/the inspect method is known to be reasonably fast (e.g. for a String or some "leaf" object) it's fine, but in general it's not fine to include arbitrary obj.inspect in error messages, it's too expensive and too slow.

Updated by Eregon (Benoit Daloze) about 1 year ago

It might be interesting to limit the depth or maximum number of fields shown for inspect via some argument/fiber locals (so it'd work to some extent with custom #inspect)/etc.
But that should be a separate new proposal then.

Updated by mame (Yusuke Endoh) about 1 year ago

zverok (Victor Shepelev) wrote in #note-26:

Say, in a complicated algorithm working with nested data structures, undefined method transform_keys for object Array is significantly worse than undefined method transform_keys for [{id: 1, name: 'John'}].

I think this is arguable. Is the receiver often as simple as [{id: 1, name: 'John'}]? And how are the contents of the receiver helpful to debug the bug? This topic is not general, but specific to NoMethodError message. I wonder if the contents of the receiver are really so critical to debug a bug of NoMethodError.

On the other hand, I have experienced multiple times that a length #inspect swept away the terminal logs and obscured the important NoMethodError message. As far as I remember, the only information I needed for debug was the receiver class, not its contents.

Rather than talking about it with an imagination, we should actually live with the new message format and experience how (in)convenient it is, I think.

Updated by Hanmac (Hans Mackowiak) about 1 year ago

maybe we could add some conditions when the object should be printed instead of the class for NoMethodError?

  • if object overwrites method_missing and maybe respond_to_missing then print the object instead of the class
  • if the object has included or prepend modules into its singleton class, then print the object instead of real class

these are the cases i can think of that could affect the methods an object can respond to that aren't related to its class

Updated by mame (Yusuke Endoh) about 1 year ago

Discussed at the dev meeting. @matz (Yukihiro Matsumoto) is positive about the change and said he would give it a try. The message format is slightly changed as follows:

  • If the receiver is a Class, ... for class <class name> should be printed.
  • If the receiver is a Module, ... for module <module name> should be printed.
  • If the receiver is an extended object (i.e., has a singleton class), any_to_s should be used.
  • Otherwise, ... for an instance of <class name> should be printed.

Examples:

42.time    #=> undefined method `time' for an instance of Integer (NoMethodError)

class Foo
  privatee #=> undefined local variable or method 'privatee' for class Foo (NoMethodError)
end

def (o=Object.new).foo
end
o.bar      #=> undefined method `bar' for #<Object: 0xdeadbeef(any_to_s)> (NoMethodError)

I'll update my PR later. When we use the new message format and find it inconvenient, we will adjust it accordingly.

Updated by mame (Yusuke Endoh) about 1 year ago

I have updated my PR: https://github.com/ruby/ruby/pull/6950

As I was working on updating the PR, the following message change caught my attention.

old: undefined method `foo' for main:Object
new: undefined method `foo' for #<Object:0x00007f230602cd28>

Because the toplevel (main) is an extended object, any_to_s rule is applied. But I think the new message is too confusing. I talked with @matz (Yukihiro Matsumoto), and we decided to handle the toplevel specially:

new: undefined method `foo' for main

I found no other confusing examples during updating my PR.

Actions #39

Updated by mame (Yusuke Endoh) about 1 year ago

  • Status changed from Open to Closed

Applied in changeset git|8a59f75de7e1ee4c021a1cd79aa78f0c6cf78507.


Use the development versions of minitest and debug gems

This is a preparation for a new message format of NameError.
[Feature #18285]

https://github.com/minitest/minitest/pull/942
https://github.com/ruby/debug/pull/889

Updated by ivoanjo (Ivo Anjo) about 1 year ago

Thank you! :)

Updated by Eregon (Benoit Daloze) about 1 year ago

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

new: undefined method `foo' for main

I think that's quite confusing though without the main:Object, because main has many other meanings (main script = $0, main function, etc).
So I'd suggest either:

undefined method `foo' for main:Object
undefined method `foo' for main object
Actions #42

Updated by Eregon (Benoit Daloze) 11 months ago

  • Related to Feature #19520: Support for `Module.new(name)` and `Class.new(superclass, name)`. added
Actions #43

Updated by mame (Yusuke Endoh) 5 months ago

  • Has duplicate Feature #19978: NoMethodError and large objects should not create unwieldy error messages added

Updated by headius (Charles Nutter) 2 months ago

Also fixes my issue from 2014: https://bugs.ruby-lang.org/issues/9725

I'm glad we finally have dealt with this one.

Actions #45

Updated by headius (Charles Nutter) 2 months ago

  • Is duplicate of Feature #9725: Do not inspect NameError target object unless verbose added
Actions

Also available in: Atom PDF

Like1
Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like0Like2Like0Like0Like0Like0Like0Like0Like1Like0