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

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





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



I am just saying that the way of fixing it by replacing the object represen=
tation with class name breaks many good use cases and, in general, seems le=
ss friendly to me.

It always felt nice and informative.



Interesting to note that the latest Ruby releases tend to add _more_ contex=
t for errors (with `did_you_mean` and `error_highlight`), and it is conside=
red a good thing, while this change seems to go in the exactly opposite dir=
ection.



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 `NoMet=
hodError#detailed_message`?.. It seems to be introduced exactly to handle t=
he balance between the efficiency/brevity of the "core" message and helpful=
ness.



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

1. What if `#inspect` output is too long? Intuitively, I would say that the=
re are many techniques of mechanical shortening of the string to the desire=
d limit. Say, modern IRB handles it quite gracefully (this is a copy-paste =
of FULL IRB session, the `...` is what it did):

  ```

  >> ary =3D [{a: 1, foo: :bar}] * 100

  =3D>=20

  [{:a=3D>1, :foo=3D>:bar},                                                =
             =20

  ...                          =20

  ```

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 knif=
e"-class responsibility, it is rather "if you've implemented `to_s` to retu=
rn a number, nothing would work properly"), but b) maybe the `detailed_mess=
age` idea helps mitigating this, anyway?..=20



----------------------------------------

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.co=
m/DataDog/dd-trace-rb and we ran into this issue on one of our internal tes=
ting applications. I also blogged about this issue in <https://ivoanjo.me/b=
log/2021/11/01/nomethoderror-ruby-cost/>.



### Background



While testing an application that threw a lot of `NoMethodError`s in a Rail=
s controller (this was used for validation), we discovered that service per=
formance was very much impacted when we were logging these exceptions. Whil=
e investigating with a profiler, the performance impact was caused by calls=
 to `NoMethodError#message`, because this Rails controller had a quite comp=
lex `#inspect` method, that was getting called every time we tried to get t=
he `#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 =3D> e

    e

  end



  def get_runtime_error

    raise 'Another Error'

  rescue =3D> e

    e

  end



  def inspect # <-- expensive method gets called when calling NoMethodError=
#message

    Gem::Specification._all.inspect

  end

end



NO_METHOD_ERROR_INSTANCE =3D GemInformation.new.get_no_method_error

RUNTIME_ERROR_INSTANCE =3D GemInformation.new.get_runtime_error



Benchmark.ips do |x|

  x.config(:time =3D> 5, :warmup =3D> 2)



  x.report("no method error message cost") { NO_METHOD_ERROR_INSTANCE.messa=
ge }

  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 gett=
ing 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  (=B1 1.7%) i/s -    580.000  in   5.027822s

runtime error message cost

                          6.938M (=B1 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  (=B1 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/e0915ba67964d843832148aeca29a1f8244c=
a7b1/error.c#L1962>)

2. Cache result of calling `#message` after the first call. Ideally this sh=
ould be done together with suggestion 1.









--=20

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

 ______________________________________________
 ruby-core mailing list -- [e-mail]
 To unsubscribe send an email to [e-mail]
 ruby-core info -- https://ml.ruby-lang.org/mailman3/postorius/lists/ruby-c=
ore.ml.ruby-lang.org/