[ruby-core:106922] [Ruby master Bug#18452] Dramatic performance regression in Zeitwerk with 3.1

Issue #18452 has been updated by fxn (Xavier Noria).


> I think your original assumption is more reasonable, and Bootsnap's assumption is not.

OK, thanks for the hint.

> I'm also not sure what code is expecting a Kernel#require with a directory to work, but such code also seems suspect, IMO. If you've only made this change to Zeitwerk in the last week, I recommend reverting it.

In projects managed by Zeitwerk, subdirectories represent namespaces. If the namespace has a file defining it, all is normal, but if there is no explicit file, the library is expected to create a dummy module object and assign it to the corresponding constant.

Now, there's a general expectation in Zeitwerk that says that things are loaded on demand, when referenced. In order to do so and be symmetric with everything else, Zeitwerk defines an autoload on the directory. That is, if you have

```
app/controllers/admin
```

and no `admin.rb` anywhere, it executes `autoload :Admin, "full/path/to/app/controllers/admin"`. Then, the `require` wrapper intercepts that call, autovivifies, does housekeeping **and does not call the original method**. The autoload is hijacked.

And this has worked flawlessly since it first shipped about two years ago. Pushing to `$LOADED_FEATURES` is something new that has been out only for a few days.

Thanks for the explanation on the index being rebuilt!

I think we can close Jeremy, I'll follow your advice and revert. Thanks for your help.

----------------------------------------
Bug #18452: Dramatic performance regression in Zeitwerk with 3.1
https://bugs.ruby-lang.org/issues/18452#change-95743

* Author: fxn (Xavier Noria)
* Status: Open
* Priority: Normal
* Backport: 2.6: UNKNOWN, 2.7: UNKNOWN, 3.0: UNKNOWN, 3.1: UNKNOWN
----------------------------------------
Hi!

In Ruby 3.1, Zeitwerk loads implicit namespaces way slower than in previous versions. In this benchmark:

```ruby
require 'fileutils'
require 'tmpdir'
require 'zeitwerk'

Dir.mktmpdir do |dir|
  Dir.chdir(dir)

  for i in 'a'..'z'
    for j in 'a'..'z'
      FileUtils.mkdir_p("lib/#{i}/#{j}")
    end
  end

  loader = Zeitwerk::Loader.new
  loader.push_dir('lib')
  loader.setup

  start = Process.clock_gettime(Process::CLOCK_MONOTONIC)
  loader.eager_load
  puts Process.clock_gettime(Process::CLOCK_MONOTONIC) - start
end
```

you go from about 0.06s to +11s. That is like a **180x slow down** .

I have seen that the single cause of the slow down is one line: Zeitwerk's `Kernel#require` wrapper pushing to `$LOADED_FEATURES` when it intercepts a directory [source code](https://github.com/fxn/zeitwerk/blob/1ff6336d937514c923f2c5a60cfaa501f150a7b5/lib/zeitwerk/kernel.rb#L32). For context, Zeitwerk sets autoloads for directories that define namespaces, so that their corresponding modules get autovivified when first referenced by the user.

I have written a self-contained script that reproduces the root of the issue without Zeitwerk, in case that helps debugging:

```ruby
module Kernel
  alias original_require require

  def require(path)
    if path.start_with?('/foo')
      $LOADED_FEATURES << path
      true
    else
      original_require(path)
    end
  end
end

foos = []
('a'..'z').each do |i|
  ('a'..'z').each do |j|
    foos << "/foo#{i}#{j}"
  end
end

start = Process.clock_gettime(Process::CLOCK_MONOTONIC)
foos.each { |foo| require foo }
puts Process.clock_gettime(Process::CLOCK_MONOTONIC) - start
```

I have seen that [this commit](https://github.com/ruby/ruby/commit/79a4484a072e9769b603e7b4fbdb15b1d7eccb15) is responsible for the majority of the regression, But it is not the only cause, before that commit, the script is faster, but not as fast by an important factor too.



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

Unsubscribe: <mailto:[e-mail]?subject=unsubscribe>
<http://lists.ruby-lang.org/cgi-bin/mailman/options/ruby-core>