Bug #15856
Idempotent performance of Kernel.require with many activated gems is slow
Description
With many activated gems the performance of Kernel.require (aka Kernel.gem_original_require after rubygems is loaded) is very slow, even in the case where the require has already been loaded (the idempotent case).
What it looks like is happening is every time it needs to resolve the string argument to a pathname in order to compare against a cache of already loaded paths. Since require and require_relative need to be able to share state this makes sense to do, but this becomes very expensive with lots of activated gems, particularly on windows (where open/stat on windows is 10x more expensive than on linux).
What probably needs to happen is that for require (but not require_relative which is already fairly fast) there needs to a be another layer of idempotency checking that happens which compares only the string argument in a Hash to see if the key exists or not (which I believe is likely the old way that require used to work before require_relative was introduced). That means that on the second time a require line was processed it would find that value was true and would short circuit without doing any File I/O to resolve the filename. Of course the first time it still would need to do the check resolve to the full path and still maintain that cache so that require and require_relative were still idempotent between them.
After doing some testing I don't think this would introduce any user-visible behavior changes, since requires lines should always be idempotent. I thought it would fix some actual bugs in behavior but I was unable to "trick" the existing loader into double-loading a requires line even though I tried installing and activating gems after having already required system libs. Since I couldn't find any bugs, though, that also means that this should be backwards compatible with existing behavior.
An strace of the process of a single require "openssl", after it has been already required looks like this:
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/uuidtools-2.1.5/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/chef-bin-15.0.276/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/public_suffix-3.0.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/addressable-2.6.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/mixlib-shellout-2.4.4/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/mixlib-cli-2.0.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/appbundler-0.12.5/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/bcrypt_pbkdf-1.0.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/extensions/x86_64-linux/2.6.0/bcrypt_pbkdf-1.0.1/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/debug_inspector-0.0.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/extensions/x86_64-linux/2.6.0/debug_inspector-0.0.3/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/binding_of_caller-0.8.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/extensions/x86_64-linux/2.6.0/binding_of_caller-0.8.0/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/builder-3.2.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/byebug-11.0.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/extensions/x86_64-linux/2.6.0/byebug-11.0.1/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/tomlrb-1.2.8/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/mixlib-config-3.0.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/fuzzyurl-0.9.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/chef-config-15.0.276/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/net-ssh-5.2.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/net-scp-2.0.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/erubis-2.7.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/ffi-1.10.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/extensions/x86_64-linux/2.6.0/ffi-1.10.0/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/gssapi-1.3.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/gyoku-1.3.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/httpclient-2.8.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/little-plugger-1.1.4/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/multi_json-1.13.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/logging-2.2.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/nori-2.6.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/rubyntlm-0.6.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/winrm-2.3.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/rubyzip-1.2.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/winrm-fs-1.3.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/train-core-2.1.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/equatable-0.5.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/tty-color-0.4.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/pastel-0.7.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/tty-cursor-0.6.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/strings-ansi-0.1.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/unicode_utils-1.4.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/unicode-display_width-1.4.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/strings-0.1.4/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/tty-box-0.3.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/necromancer-0.4.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/timers-4.3.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/wisper-2.0.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/tty-screen-0.6.5/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/tty-reader-0.5.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/tty-prompt-0.18.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/license-acceptance-1.0.5/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/mixlib-log-3.0.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/mixlib-authentication-2.1.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/mixlib-archive-1.0.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/systemu-2.6.5/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/libyajl2-1.2.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/extensions/x86_64-linux/2.6.0/libyajl2-1.2.0/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/ffi-yajl-2.3.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/extensions/x86_64-linux/2.6.0/ffi-yajl-2.3.1/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/plist-3.5.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/ipaddress-0.8.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/wmi-lite-1.0.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/ohai-15.0.34/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/net-ssh-gateway-2.0.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/net-ssh-multi-1.2.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/net-sftp-2.1.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/ed25519-1.2.4/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/extensions/x86_64-linux/2.6.0/ed25519-1.2.4/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/highline-1.7.10/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/diff-lcs-1.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/ffi-libarchive-0.4.6/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/hashie-3.6.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/uuidtools-2.1.5/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/rack-2.0.7/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/chef-zero-14.0.12/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/iniparse-1.4.4/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/syslog-logger-1.6.8/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/proxifier-1.0.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/chef-15.0.276/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/chef-bin-15.0.276/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/chef-vault-3.4.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/cheffish-14.0.4/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/coderay-1.1.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/safe_yaml-1.0.5/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/crack-0.4.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/docile-1.3.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/multipart-post-2.0.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/faraday-0.15.4/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/faraday_middleware-0.12.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/hashdiff-0.3.9/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/htmlentities-4.3.4/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/thor-0.20.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/method_source-0.9.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/rspec-support-3.8.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/rspec-core-3.8.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/rspec-expectations-3.8.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/rspec-mocks-3.8.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/rspec-3.8.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/rspec-its-1.3.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/pry-0.12.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/sslshake-1.3.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/parallel-1.17.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/parslet-1.8.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/semverse-3.0.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/tty-table-0.10.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/tins-1.20.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/term-ansicolor-1.7.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/inspec-core-4.3.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/json-2.2.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/extensions/x86_64-linux/2.6.0/json-2.2.0/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/pry-byebug-3.7.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/slop-3.6.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/pry-remote-0.1.8/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/pry-stack_explorer-0.4.9.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/rake-12.3.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/rb-readline-0.5.5/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/rspec_junit_formatter-0.2.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/ruby-prof-0.17.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/extensions/x86_64-linux/2.6.0/ruby-prof-0.17.0/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/ruby-shadow-2.5.0/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/extensions/x86_64-linux/2.6.0/ruby-shadow-2.5.0/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/simplecov-html-0.10.2/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/simplecov-0.16.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/webmock-3.5.1/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/gems/2.6.0/gems/bundler-1.17.3/lib/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/site_ruby/2.6.0/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/site_ruby/2.6.0/x86_64-linux/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/site_ruby/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/vendor_ruby/2.6.0/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/vendor_ruby/2.6.0/x86_64-linux/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/vendor_ruby/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/opt/chef/embedded/lib/ruby/2.6.0/openssl.rb", O_RDONLY|O_NONBLOCK|O_CLOEXEC) = 7
On windows, taking this much I/O on every single require line, can quickly add up to 100,000s of open calls, which takes several seconds on an SSD and can take upwards of a minute on a spinning drive just to evaluate the requires of an application that does no work (i.e. command line tooling).
History
Updated by hsbt (Hiroshi SHIBATA) 8 months ago
Updated by - Assignee set to hsbt (Hiroshi SHIBATA)
- Status changed from Open to Assigned
Updated by deivid (David RodrÃguez) 8 months ago
Updated by I had a look at this. I manage to reproduce the issue only when requiring openssl. In general, I think it can be reproduced when a ruby feature requires an dynamic library of the same name. In this case, require "openssl" resolves to requiring openssl.rb, which internally requires (among other stuff) openssl.so.
To reproduce, I required openssl a lot of times, expecting that after the first time the require would have no overhead. However,
$ time ruby --disable-gems -e '100000.times { require "openssl" }'
real 0m3,075s
user 0m1,732s
sys 0m1,301s
The problem can be workaround by explicitly specifying the file extension
$ time ruby --disable-gems -e '100000.times { require "openssl.rb" }'
real 0m0,137s
user 0m0,113s
sys 0m0,029s
I took a lot at fixing it and came up with this patch
diff --git a/load.c b/load.c
index 576464fb68..ae89f63820 100644
--- a/load.c
+++ b/load.c
@@ -908,6 +908,11 @@ search_required(VALUE fname, volatile VALUE *path, int safe_level, feature_func
if (loading) *path = rb_filesystem_str_new_cstr(loading);
return 'r';
}
+ else if ((ft = rb_feature_p(ftptr, 0, FALSE, FALSE, &loading)) == 's') {
+ if (loading) *path = rb_filesystem_str_new_cstr(loading);
+ return 's';
+ }
+
tmp = fname;
type = rb_find_file_ext_safe(&tmp, loadable_ext, safe_level);
switch (type) {
However, that breaks the following spec:
it "loads a .rb extensioned file when a C-extension file of the same name is loaded" do
$LOADED_FEATURES << File.expand_path("load_fixture.bundle", CODE_LOADING_DIR)
$LOADED_FEATURES << File.expand_path("load_fixture.dylib", CODE_LOADING_DIR)
$LOADED_FEATURES << File.expand_path("load_fixture.so", CODE_LOADING_DIR)
$LOADED_FEATURES << File.expand_path("load_fixture.dll", CODE_LOADING_DIR)
path = File.expand_path "load_fixture", CODE_LOADING_DIR
@object.require(path).should be_true
ScratchPad.recorded.should == [:loaded]
end
I'm not sure that spec is expected behavior, though. It was introduced during this refactoring, but I think the refactoring changed the expectations, because the previous spec I think this spec comes from reads like this:
it "will load file.rb when given 'file' if it exists even if file.<ext> is loaded" do
$LOADED_FEATURES << "require_spec_3.#{Config::CONFIG['DLEXT']}"
require('require_spec_3.rb').should be_true
$LOADED_FEATURES.grep(/require_spec_3\.rb/).should_not == []
end
and while the description is what the spec tests nowadays, the implementation explictly included a file extension (require_spec_3.rb), while the current spec does not (load_fixture).
Essentially I think it comes down to whether the correct behavior is the current one:
$ ruby --disable-gems -e 'puts require "openssl.so"; puts require "openssl"' true true
or the one after my patch:
$ ruby --disable-gems -e 'puts require "openssl.so"; puts require "openssl"' true false
If the expected behavior is the current one, then obviously my patch doesn't work.
Updated by lamont (Lamont Granquist) 8 months ago
Updated by Okay that explains what I was seeing, I just didn't realize that it was that subtle around .so loading, but I think I've verified that this is for those native libraries only.
I'd argue that your patch results in more correct and less surprising behavior, but I have no idea who is bug dependent upon it.
I'm going to wind up doing a large amount of work to bypass this problem, though, and decorating all our code with require "openssl" unless defined?(OpenSSL) old-school tactics from 8+ years ago as a workaround. I would definitely vote to change this behavior in core.
And I've already had users reading my code patches and I'm worried about I'm about to start a cargo cult of how to make ruby go fast.
Updated by lamont (Lamont Granquist) 2 months ago
For what its worth:
We went ahead and incorporated the prior patch into chef's shipping packages starting with Chef 15.5.9, and it will be incorporated into all our shipping products that bake in ruby (inspec, chefdk, chef workstation, supermarket, etc).
I'd like to encourage the consideration of accepting that patch for Ruby 3.0 and breaking that one use case in the ruby specs, assuming we don't turn up any issues by deploying it into "production".
Updated by Eregon (Benoit Daloze) 2 months ago
Updated by I agree caching require 'openssl' should be possible.
I'm OK with changing (or removing) that spec to specify the new behavior, but would like to hear others' opinions as I don't much about the history and rationale behind the current behavior.
Updated by lamont (Lamont Granquist) about 2 months ago
I tracked it back to the initial commit in the ruby-spec repo:
That is from May 2008 and there's no history in git beyond that, or any note of why it is there.
Maybe someone else who knows the history of where that repo came from in the first place can dig up history even further back, but that's where the trail goes cold for me.
Updated by Dan0042 (Daniel DeLorme) about 2 months ago
Updated by A quick search yields the following files that have both a rb and so version:
/opt/ruby/2.7/lib/ruby/gems/2.7.0/gems/redcarpet-3.5.0/lib redcarpet.so /opt/ruby/2.7/lib/ruby/gems/2.7.0/gems/debug_inspector-0.0.3/lib debug_inspector.so /opt/ruby/2.7/lib/ruby/2.7.0 ripper.so (required from ripper/core.so) bigdecimal/util.so monitor.so pathname.so fiddle.so digest.so digest/sha2.so (from digest/sha2.rb AND digest.rb) bigdecimal.so psych.so coverage.so socket.so readline.so openssl.so
Except for ripper and digest/sha2, the so is required from within the rb.
digest/sha2 is kinda interesting because it ties into Digest auto-loading. Using Digest::SHA256 will load "digest/sha2.so", and then if you use Digest::SHA2 that will attempt to load "digest/sha2". I think that would not work with the above patch.