[#106355] [Ruby master Bug#18373] RBS build failure: '/include/x86_64-linux/ruby/config.h', needed by 'constants.o'. — "vo.x (Vit Ondruch)" <noreply@...>
Issue #18373 has been reported by vo.x (Vit Ondruch).
28 messages
2021/12/01
[ruby-core:106919] [Ruby master Bug#18452] Dramatic performance regression in Zeitwerk with 3.1
From:
"fxn (Xavier Noria)" <noreply@...>
Date:
2021-12-30 15:56:33 UTC
List:
ruby-core #106919
Issue #18452 has been updated by fxn (Xavier Noria).
> Is there a reason Zeitwerk is adding directories to $LOADED_FEATURES, instead of using its own data structure?
It didn't do that since it first shipped. The lib intercepted the `require` and did its thing without invoking the original method. It hijacked the call and nobody noticed. This has worked fine since forever.
But last week I got a report about some namespaces not loading. The reason for that was that the project loaded Zeitwerk first, and Bootsnap later. Both decorate `require`. Bootsnap assumes a successful `require` puts its argument in `$LOADED_FEATURES` and caches the directory internally. And that prevented reload, because `$LOADED_FEATURES` did not have the directory to clean it up, and the cache of Bootsnap became out of sync.
I thought about different options, and believed that Bootsnap made a reasonable assumption, so just a few days ago I pushed a new version that pushed the directory to `$LOADED_FEATURES`.
You are right about directories being unexpected in that collection, see my [comment](https://github.com/fxn/zeitwerk/issues/198#issuecomment-1001539203) in the original issue.
You are also right about the self-contained script. I missed some scientific notation and misread some numbers. These are the figures:
```
BEFORE 79a4484a07
% ./ruby -v ~/tmp/foo.rb
ruby 3.1.0dev (2021-10-02T14:51:29Z v3_1_0_preview1~1463 3f7da458a7) [x86_64-darwin21]
/Users/fxn/prj/zeitwerk/lib/zeitwerk/kernel.rb:24: warning: method redefined; discarding old require
Zeitwerk: 0.28963999999905354
Self-contained: 0.000389000000723172
AFTER 79a4484a07
% ./ruby -v ~/tmp/foo.rb
ruby 3.1.0dev (2021-10-02T14:51:29Z v3_1_0_preview1~1462 79a4484a07) [x86_64-darwin21]
/Users/fxn/prj/zeitwerk/lib/zeitwerk/kernel.rb:24: warning: method redefined; discarding old require
Zeitwerk: 11.44435700000031
Self-contained: 9.200000022246968e-05
```
As you see, the reported impact happens in the script using Zeitwerk.
Every `require` call pushes to `$LOADED_FEATURES`, and if I comment out the line that pushes to `$LOADED_FEATURES` in Zeitwerk performance is not affected. Why is the lib's `push` more costly?
----------------------------------------
Bug #18452: Dramatic performance regression in Zeitwerk with 3.1
https://bugs.ruby-lang.org/issues/18452#change-95738
* 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:ruby-core-request@ruby-lang.org?subject=unsubscribe>
<http://lists.ruby-lang.org/cgi-bin/mailman/options/ruby-core>