[ruby-core:111660] [Ruby master Feature#18285] NoMethodError#message uses a lot of CPU/is really expensive to call

5 Jan 2023

      Issue #18285 has been updated by zverok (Victor Shepelev).

@byroot 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},                                                              
  ...
2. 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?.. 

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

* 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 &lt;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 # &lt;-- 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/