[#111712] [Ruby master Feature#19322] Support spawning "private" child processes — "kjtsanaktsidis (KJ Tsanaktsidis) via ruby-core" <ruby-core@...>
SXNzdWUgIzE5MzIyIGhhcyBiZWVuIHJlcG9ydGVkIGJ5IGtqdHNhbmFrdHNpZGlzIChLSiBUc2Fu
14 messages
2023/01/07
[ruby-core:111725] [Ruby master Feature#18285] NoMethodError#message uses a lot of CPU/is really expensive to call
From:
"ivoanjo (Ivo Anjo) via ruby-core" <ruby-core@...>
Date:
2023-01-07 13:23:34 UTC
List:
ruby-core #111725
Issue #18285 has been updated by ivoanjo (Ivo Anjo).
> The vast majority of classes out there don't define a custom inspect. So =
Ruby should do something reasonable for these cases.
+1 My intention with my bug report was to call this out -- `inspect` can ge=
t really expensive, and you just need a complex object graph where every ob=
ject uses the default inspect to cause that.
And in my very humble opinion this is fine, because the way I've always see=
n it is that `#inspect` is supposed to be something that gets used while de=
bugging, not in production. E.g. my base assumption is: in production the c=
ommon case is that `#inspect` is never called. (Unless some production debu=
gging tool is using it explicitly)
The footgun happens when `#inspect` is combined with `NoMethodError`, which=
is definitely something that can happen in production, and can be triggere=
d by both typos as well as (as pointed out above) duck/dynamic-typing bugs.
I like @mame 's PR since it avoids this issue in the default case, thus loc=
king away the footgun. And it creates a new question -- how to get at this =
useful information while debugging?
@zverok 's idea of using `NoMethodError#detailed_message` seems interesting=
when combined with https://github.com/ruby/ruby/pull/6950. Maybe some kind=
of combination is an interesting answer for this issue?
----------------------------------------
Feature #18285: NoMethodError#message uses a lot of CPU/is really expensive=
to call
https://bugs.ruby-lang.org/issues/18285#change-101125
* 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 -- [email protected]
To unsubscribe send an email to [email protected]
ruby-core info -- https://ml.ruby-lang.org/mailman3/postorius/lists/ruby-c=
ore.ml.ruby-lang.org/