From: "zverok (Victor Shepelev) via ruby-core" Date: 2023-01-05T10:07:56+00:00 Subject: [ruby-core:111649] [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). 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) > > 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) 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](https://bugs.ruby-lang.org/issues/18285#note-6) is also interesting���but I don't believe that "just never use `#inspect` is a good solution for it either. ---------------------------------------- Feature #18285: NoMethodError#message uses a lot of CPU/is really expensive to call https://bugs.ruby-lang.org/issues/18285#change-101039 * 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 . ### 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 ) 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/