From: "Eregon (Benoit Daloze)" <noreply@...>
Date: 2021-11-03T23:39:19+00:00
Subject: [ruby-core:105923] [Ruby master Misc#18285] NoMethodError#message uses a lot of CPU/is really expensive to call

Issue #18285 has been updated by Eregon (Benoit Daloze).


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:
```ruby
# 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)
```

----------------------------------------
Misc #18285: NoMethodError#message uses a lot of CPU/is really expensive to call
https://bugs.ruby-lang.org/issues/18285#change-94465

* Author: ivoanjo (Ivo Anjo)
* Status: Open
* Priority: Normal
----------------------------------------
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 `NoMethodError`s 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

```ruby
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.




-- 
https://bugs.ruby-lang.org/

Unsubscribe: <mailto:ruby-core-request@ruby-lang.org?subject=unsubscribe>
<http://lists.ruby-lang.org/cgi-bin/mailman/options/ruby-core>