From: "mame (Yusuke Endoh) via ruby-core" <ruby-core@...>
Date: 2023-01-10T07:04:47+00:00
Subject: [ruby-core:111768] [Ruby master Feature#18285] NoMethodError#message uses a lot of CPU/is really expensive to call

Issue #18285 has been updated by mame (Yusuke Endoh).





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.





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

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

https://bugs.ruby-lang.org/issues/18285#change-101176



* 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/

 ______________________________________________
 ruby-core mailing list -- ruby-core@ml.ruby-lang.org
 To unsubscribe send an email to ruby-core-leave@ml.ruby-lang.org
 ruby-core info -- https://ml.ruby-lang.org/mailman3/postorius/lists/ruby-core.ml.ruby-lang.org/