28 Feb
2023
28 Feb
'23
4:04 p.m.
Issue #19246 has been updated by MSP-Greg (Greg L).
This does seem like a considerable slowdown on Windows.
The above code uses absolute paths with `require`, and also adds nonexistent files to
`$LOADED_FEATURES`. I changed the code so that all requires are simply a
`File.basename`,
and the items pushed to `$LOADED_FEATURES` are real files. Below is data for several Ruby
versions, run with both Windows and WSL2/Ubuntu 22.04.
The 'normal' & normal again' benches each require 200 files. The
'loaded features' bench requires 200 files, and additionally adds 200 different
file names to `$LOADED_FEATURES`.
Adding items to `$LOADED_FEATURES` has worse performance with Ruby 3.1 and later on both
Windows & Ubuntu, but the Windows degradation is orders of magnitude larger.
[Issue 19378 'Windows: Use less syscalls for faster require of big
gems'](https://bugs.ruby-lang.org/issues/19378) seems to involve the same problem.
Windows
```
user system total real
ruby 2.7.7p221 (2022-11-24 revision 168ec2b1e5) [x64-mingw32]
normal 0.016000 0.047000 0.063000 ( 0.103496)
loaded features 0.031000 0.031000 0.062000 ( 0.157406)
normal again 0.000000 0.094000 0.094000 ( 0.100160)
ruby 3.0.5p211 (2022-11-24 revision ba5cf0f7c5) [x64-mingw32]
normal 0.000000 0.063000 0.063000 ( 0.100240)
loaded features 0.032000 0.031000 0.063000 ( 0.156637)
normal again 0.000000 0.062000 0.062000 ( 0.098520)
ruby 3.1.0p0 (2021-12-25 revision fb4df44d16) [x64-mingw-ucrt]
normal 0.000000 0.062000 0.062000 ( 0.174335)
loaded features 3.141000 18.860000 22.001000 ( 33.106847)
normal again 0.015000 0.265000 0.280000 ( 0.400028)
ruby 3.1.3p185 (2022-11-24 revision 1a6b16756e) [x64-mingw-ucrt]
normal 0.000000 0.157000 0.157000 ( 0.168443)
loaded features 3.516000 18.547000 22.063000 ( 32.569175)
normal again 0.047000 0.218000 0.265000 ( 0.390879)
ruby 3.3.0dev (2023-02-27T15:23:31Z master ea830ab29d) [x64-mswin64_140]
normal 0.015000 0.094000 0.109000 ( 0.175751)
loaded features 3.235000 16.640000 19.875000 ( 31.294871)
normal again 0.031000 0.203000 0.234000 ( 0.386469)
user system total real
require 800 0.015000 0.235000 0.250000 ( 0.391236) ruby 2.7.7p221
require 800 0.078000 0.156000 0.234000 ( 0.391100) ruby 3.0.5p211
require 800 0.031000 0.484000 0.515000 ( 0.664927) ruby 3.1.0p0
require 800 0.109000 0.391000 0.500000 ( 0.651035) ruby 3.1.3p185
require 800 0.062000 0.406000 0.468000 ( 0.704620) ruby 3.3.0dev
Note: Ruby master timing is similar for mingw, ucrt, & mswin builds
```
WSL2/Ubuntu
```
user system total real
ruby 2.7.7p221 (2022-11-24 revision 168ec2b1e5) [x86_64-linux]
normal 0.001399 0.002799 0.004198 ( 0.004197)
loaded features 0.065028 0.000000 0.065028 ( 0.065073)
normal again 0.004481 0.000000 0.004481 ( 0.004482)
ruby 3.0.4p208 (2022-04-12 revision 3fa771dded) [x86_64-linux]
normal 0.004395 0.000000 0.004395 ( 0.004394)
loaded features 0.065669 0.000000 0.065669 ( 0.065717)
normal again 0.004371 0.000000 0.004371 ( 0.004371)
ruby 3.1.0p0 (2021-12-25 revision fb4df44d16) [x86_64-linux]
normal 0.006511 0.000000 0.006511 ( 0.006505)
loaded features 0.189599 0.138964 0.328563 ( 0.328602)
normal again 0.004792 0.002796 0.007588 ( 0.007588)
ruby 3.1.3p185 (2022-11-24 revision 1a6b16756e) [x86_64-linux]
normal 0.004290 0.001430 0.005720 ( 0.005719)
loaded features 0.098113 0.210443 0.308556 ( 0.308597)
normal again 0.006900 0.000000 0.006900 ( 0.006899)
ruby 3.3.0dev (2023-02-27T21:34:27Z master ba55706fb6) [x86_64-linux]
normal 0.003708 0.001236 0.004944 ( 0.004942)
loaded features 0.118627 0.160026 0.278653 ( 0.278693)
normal again 0.000000 0.006377 0.006377 ( 0.006378)
user system total real
require 800 0.017006 0.000000 0.017006 ( 0.017004) ruby 2.7.7p221
require 800 0.016817 0.000000 0.016817 ( 0.016819) ruby 3.0.4p208
require 800 0.023295 0.000000 0.023295 ( 0.023295) ruby 3.1.0p0
require 800 0.020107 0.000000 0.020107 ( 0.020106) ruby 3.1.3p185
require 800 0.009945 0.009533 0.019478 ( 0.019476) ruby 3.3.0dev
```
----------------------------------------
Bug #19246: Rebuilding the loaded feature index much slower in Ruby 3.1
https://bugs.ruby-lang.org/issues/19246#change-102082
* Author: thomthom (Thomas Thomassen)
* Status: Open
* Priority: Normal
* Backport: 2.7: UNKNOWN, 3.0: UNKNOWN, 3.1: UNKNOWN
----------------------------------------
Some background to this issue: (This is a case that is unconventional usage of Ruby, but I
hope you bear with me.)
We ship the Ruby interpreter with our desktop applications for plugin support in our
application (SketchUp).
One feature we have had since, at least 2006 (maybe earlier-hard to track history beyond
that) is that we had a custom alternate `require` method: `Sketchup.require`. This allows
the users of our API to load encrypted Ruby files.
This originally used `rb_provide` to add the path to the encrypted file into the list of
loaded feature. However, somewhere between Ruby 2.2 and 2.5 there was some string
optimisations made and the function `rb_provide` would not use a copy of the string passed
to it. Instead it just held on to a pointer reference. In our case that string came from
user-land, being passed in from `Sketchup.require` and would eventually be garbage
collected and cause access violation crashes.
To work around that we changed our custom `Sketchup.require` to push to `$LOADED_FEATURES`
directly. There was a small penalty to the index being rebuilt after that, but it was
negligible.
Recently we tried to upgrade the Ruby interpreter in our application from 2.7 to 3.1 and
found a major performance reduction when using our `Sketchup.require. As in, a plugin that
would load in half a second would now spend 30 seconds.
From https://bugs.ruby-lang.org/issues/18452 it sounds like there is _some_ expected extra
penalty due to changes in how the index is built. But should it really be this much?
Example minimal repro to simulate the issue:
```
# frozen_string_literal: true
require 'benchmark'
iterations = 200
foo_files = iterations.times.map { |i| "#{__dir__}/tmp/foo-#{i}.rb" }
foo_files.each { |f| File.write(f, "") }
bar_files = iterations.times.map { |i| "#{__dir__}/tmp/bar-#{i}.rb" }
bar_files.each { |f| File.write(f, "") }
biz_files = iterations.times.map { |i| "#{__dir__}/tmp/biz-#{i}.rb" }
biz_files.each { |f| File.write(f, "") }
Benchmark.bm do |x|
x.report('normal') {
foo_files.each { |file|
require file
}
}
x.report('loaded_features') {
foo_files.each { |file|
require file
$LOADED_FEATURES << "#{file}-fake.rb"
}
}
x.report('normal again') {
biz_files.each { |file|
require file
}
}
end
```
```
C:\Users\Thomas\SourceTree\ruby-perf>ruby27.bat
ruby 2.7.4p191 (2021-07-07 revision a21a3b7d23) [x64-mingw32]
C:\Users\Thomas\SourceTree\ruby-perf>ruby test-require.rb
user system total real
normal 0.000000 0.031000 0.031000 ( 0.078483)
loaded_features 0.015000 0.000000 0.015000 ( 0.038759)
normal again 0.016000 0.032000 0.048000 ( 0.076940)
```
```
C:\Users\Thomas\SourceTree\ruby-perf>ruby30.bat
ruby 2.7.4p191 (2021-07-07 revision a21a3b7d23) [x64-mingw32]
C:\Users\Thomas\SourceTree\ruby-perf>ruby test-require.rb
user system total real
normal 0.000000 0.031000 0.031000 ( 0.074733)
loaded_features 0.032000 0.000000 0.032000 ( 0.038898)
normal again 0.000000 0.047000 0.047000 ( 0.076343)
```
```
C:\Users\Thomas\SourceTree\ruby-perf>ruby31.bat
ruby 3.1.2p20 (2022-04-12 revision 4491bb740a) [x64-mingw-ucrt]
C:\Users\Thomas\SourceTree\ruby-perf>ruby test-require.rb
user system total real
normal 0.016000 0.031000 0.047000 ( 0.132633)
loaded_features 1.969000 11.500000 13.469000 ( 18.395761)
normal again 0.031000 0.125000 0.156000 ( 0.249130)
```
Right now we're exploring options to deal with this. Because the performance
degradation is a blocker for us upgrading. We also have 16 years of plugins created by
third party developer that makes it impossible for us to drop this feature.
Some options as-is, none of which are ideal:
1. We revert to using `rb_provide` but ensure the string passed in is not owned by Ruby,
instead building a list of strings that we keep around for the duration of the application
process. The problem is that some of our plugin developers have on occasion released
plugins that will touch `$LOADED_FEATURES`, and if such a plugin is installed on a user
machine it might cause the application to become unresponsive for minutes. The other
non-ideal issue with using `rb_provide` is that we're also using that in ways it
wasn't really intended (from that I understand). And it's not an official API?
2. We create a separate way for our `Sketchup.require` to keep track of it's loaded
features, but then that would diverge even more from the behaviour of `require`.
Replicating `require` functionality is not trivial and would be prone to subtle errors and
possible diverge. It also doesn't address our issue that there is code out there in
existing plugins that touches `$LOADED_FEATURES`. (And it's not something we can just
ask people to clean up. From previous experience old versions stick around for a long time
and is very hard to purge from circulation.)
I have two questions for the Ruby mantainers:
1. Would it be reasonable to see an API for adding/removing/checking `$LOADED_FEATURE`
that would allow for a more ideal implementation of a custom `require` functionality?
2. Is the performance difference in rebuilding the loaded feature index really expected to
be as high as what we're seeing? An increase of nearly 100 times? Is there something
there that might be addressed to make the rebuild to be less expensive against? (This
would really help to address our challenges with third party plugins occasionally touching
the global.)
--
https://bugs.ruby-lang.org/