https://redmine.ruby-lang.org/https://redmine.ruby-lang.org/favicon.ico?17113305112019-05-16T23:23:48ZRuby Issue Tracking SystemRuby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=780492019-05-16T23:23:48Zhsbt (Hiroshi SHIBATA)hsbt@ruby-lang.org
<ul><li><strong>Status</strong> changed from <i>Open</i> to <i>Assigned</i></li><li><strong>Assignee</strong> set to <i>hsbt (Hiroshi SHIBATA)</i></li></ul><p>ref. <a href="https://github.com/rubygems/rubygems/issues/2762" class="external">https://github.com/rubygems/rubygems/issues/2762</a></p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=780922019-05-20T15:43:41Zdeivid (David Rodríguez)
<ul></ul><p>I had a look at this. I manage to reproduce the issue only when requiring <code>openssl</code>. In general, I think it can be reproduced when a ruby feature requires an dynamic library of the same name. In this case, <code>require "openssl"</code> resolves to requiring <code>openssl.rb</code>, which internally requires (among other stuff) <code>openssl.so</code>.</p>
<p>To reproduce, I required openssl a lot of times, expecting that after the first time the require would have no overhead. However,</p>
<pre><code>$ time ruby --disable-gems -e '100000.times { require "openssl" }'
real 0m3,075s
user 0m1,732s
sys 0m1,301s
</code></pre>
<p>The problem can be workaround by explicitly specifying the file extension</p>
<pre><code>$ time ruby --disable-gems -e '100000.times { require "openssl.rb" }'
real 0m0,137s
user 0m0,113s
sys 0m0,029s
</code></pre>
<p>I took a lot at fixing it and came up with this patch</p>
<pre><code class="diff syntaxhl" data-language="diff"><span class="gh">diff --git a/load.c b/load.c
index 576464fb68..ae89f63820 100644
</span><span class="gd">--- a/load.c
</span><span class="gi">+++ b/load.c
</span><span class="p">@@ -908,6 +908,11 @@</span> search_required(VALUE fname, volatile VALUE *path, int safe_level, feature_func
if (loading) *path = rb_filesystem_str_new_cstr(loading);
return 'r';
}
<span class="gi">+ else if ((ft = rb_feature_p(ftptr, 0, FALSE, FALSE, &loading)) == 's') {
+ if (loading) *path = rb_filesystem_str_new_cstr(loading);
+ return 's';
+ }
+
</span> tmp = fname;
type = rb_find_file_ext_safe(&tmp, loadable_ext, safe_level);
switch (type) {
</code></pre>
<p>However, that breaks the following spec:</p>
<pre><code class="ruby syntaxhl" data-language="ruby"><span class="n">it</span> <span class="s2">"loads a .rb extensioned file when a C-extension file of the same name is loaded"</span> <span class="k">do</span>
<span class="vg">$LOADED_FEATURES</span> <span class="o"><<</span> <span class="no">File</span><span class="p">.</span><span class="nf">expand_path</span><span class="p">(</span><span class="s2">"load_fixture.bundle"</span><span class="p">,</span> <span class="no">CODE_LOADING_DIR</span><span class="p">)</span>
<span class="vg">$LOADED_FEATURES</span> <span class="o"><<</span> <span class="no">File</span><span class="p">.</span><span class="nf">expand_path</span><span class="p">(</span><span class="s2">"load_fixture.dylib"</span><span class="p">,</span> <span class="no">CODE_LOADING_DIR</span><span class="p">)</span>
<span class="vg">$LOADED_FEATURES</span> <span class="o"><<</span> <span class="no">File</span><span class="p">.</span><span class="nf">expand_path</span><span class="p">(</span><span class="s2">"load_fixture.so"</span><span class="p">,</span> <span class="no">CODE_LOADING_DIR</span><span class="p">)</span>
<span class="vg">$LOADED_FEATURES</span> <span class="o"><<</span> <span class="no">File</span><span class="p">.</span><span class="nf">expand_path</span><span class="p">(</span><span class="s2">"load_fixture.dll"</span><span class="p">,</span> <span class="no">CODE_LOADING_DIR</span><span class="p">)</span>
<span class="n">path</span> <span class="o">=</span> <span class="no">File</span><span class="p">.</span><span class="nf">expand_path</span> <span class="s2">"load_fixture"</span><span class="p">,</span> <span class="no">CODE_LOADING_DIR</span>
<span class="vi">@object</span><span class="p">.</span><span class="nf">require</span><span class="p">(</span><span class="n">path</span><span class="p">).</span><span class="nf">should</span> <span class="n">be_true</span>
<span class="no">ScratchPad</span><span class="p">.</span><span class="nf">recorded</span><span class="p">.</span><span class="nf">should</span> <span class="o">==</span> <span class="p">[</span><span class="ss">:loaded</span><span class="p">]</span>
<span class="k">end</span>
</code></pre>
<p>I'm not sure that spec is expected behavior, though. It was introduced during <a href="https://github.com/ruby/spec/commit/3f03b2989b9bc6d92c4c60989d0cafe604d20d50" class="external">this refactoring</a>, but I think the refactoring changed the expectations, because the previous spec I think this spec comes from reads like this:</p>
<pre><code class="ruby syntaxhl" data-language="ruby"><span class="n">it</span> <span class="s2">"will load file.rb when given 'file' if it exists even if file.<ext> is loaded"</span> <span class="k">do</span>
<span class="vg">$LOADED_FEATURES</span> <span class="o"><<</span> <span class="s2">"require_spec_3.</span><span class="si">#{</span><span class="no">Config</span><span class="o">::</span><span class="no">CONFIG</span><span class="p">[</span><span class="s1">'DLEXT'</span><span class="p">]</span><span class="si">}</span><span class="s2">"</span>
<span class="nb">require</span><span class="p">(</span><span class="s1">'require_spec_3.rb'</span><span class="p">).</span><span class="nf">should</span> <span class="n">be_true</span>
<span class="vg">$LOADED_FEATURES</span><span class="p">.</span><span class="nf">grep</span><span class="p">(</span><span class="sr">/require_spec_3\.rb/</span><span class="p">).</span><span class="nf">should_not</span> <span class="o">==</span> <span class="p">[]</span>
<span class="k">end</span>
</code></pre>
<p>and while the description is what the spec tests nowadays, the implementation explictly included a file extension (<code>require_spec_3.rb</code>), while the current spec does not (<code>load_fixture</code>).</p>
<p>Essentially I think it comes down to whether the correct behavior is the current one:</p>
<pre><code>$ ruby --disable-gems -e 'puts require "openssl.so"; puts require "openssl"'
true
true
</code></pre>
<p>or the one after my patch:</p>
<pre><code>$ ruby --disable-gems -e 'puts require "openssl.so"; puts require "openssl"'
true
false
</code></pre>
<p>If the expected behavior is the current one, then obviously my patch doesn't work.</p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=781112019-05-21T21:52:35Zlamont (Lamont Granquist)lamont@scriptkiddie.org
<ul></ul><p>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.</p>
<p>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.</p>
<p>I'm going to wind up doing a large amount of work to bypass this problem, though, and decorating all our code with <code>require "openssl" unless defined?(OpenSSL)</code> old-school tactics from 8+ years ago as a workaround. I would definitely vote to change this behavior in core.</p>
<p>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.</p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=827822019-11-25T18:44:34Zlamont (Lamont Granquist)lamont@scriptkiddie.org
<ul></ul><p>For what its worth:</p>
<p>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).</p>
<p>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".</p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=827832019-11-25T21:24:07ZEregon (Benoit Daloze)
<ul></ul><p>I agree caching <code>require 'openssl'</code> should be possible.<br>
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.</p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=829992019-12-06T18:48:28Zlamont (Lamont Granquist)lamont@scriptkiddie.org
<ul></ul><p>I tracked it back to the initial commit in the ruby-spec repo:</p>
<p><a href="https://github.com/ruby/spec/blob/6c1c34a6bbf28b55e59bc6a97a1211718082d3e7/1.8/core/kernel/require_spec.rb#L122-L126" class="external">https://github.com/ruby/spec/blob/6c1c34a6bbf28b55e59bc6a97a1211718082d3e7/1.8/core/kernel/require_spec.rb#L122-L126</a></p>
<p>That is from May 2008 and there's no history in git beyond that, or any note of why it is there.</p>
<p>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.</p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=830172019-12-09T02:36:25ZDan0042 (Daniel DeLorme)
<ul></ul><p>A quick search yields the following files that have both a rb and so version:</p>
<pre><code>/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
</code></pre>
<p>Except for ripper and digest/sha2, the so is required from within the rb.</p>
<p>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.</p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=870982020-08-17T18:08:25Zlamont (Lamont Granquist)lamont@scriptkiddie.org
<ul></ul><p>So we've been shipping this patch for 8 months now and not seen any bug reports.</p>
<p>Not sure why we haven't seen any issues around sha2/sha256, but either we get sha256 from the openssl api and not digest or that's been working, because we definitely use sha256.</p>
<p>As a breaking change the "blast radius" of this seems relatively contained. Really this is a massive perf improvement, and it would be worth it IMO to put this into ruby 3.0 and break backwards compat over this issue to get the 10x+ perf increase on those requires. It would do a lot to address "bundler sucks and is slow" issues. Also "ruby is slow on windows" since the I/O hit from all this scanning is ten times worse on windows.</p>
<p>We also are littering our code with defensive idempotency checks, to make our gems run faster when people do use them under bundler:</p>
<p><a href="https://github.com/chef/chef/commit/9dbdb769bfd963f82eb4bfea53c83501d0193766" class="external">https://github.com/chef/chef/commit/9dbdb769bfd963f82eb4bfea53c83501d0193766</a></p>
<p>I would love to stop doing that since it is horrible, but this is my "best-practice" recommendation today for ruby 2.7 bundler performance under Windows.</p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=871012020-08-18T03:06:53Zsawa (Tsuyoshi Sawada)
<ul><li><strong>Subject</strong> changed from <i>Idempotent performance of Kernel.require with many activated gems is slow</i> to <i>Performance of redundant `Kernel.require` is slow when many gems are activated</i></li><li><strong>Description</strong> updated (<a title="View differences" href="/journals/87101/diff?detail_id=57758">diff</a>)</li></ul><p>Idempotency is a property of an operation within a system. <code>require</code> may be idempotent, its particular use is not. You mean redundant, not idempotent.</p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=871042020-08-18T09:01:38ZEregon (Benoit Daloze)
<ul></ul><p>Could the feature index track that both <code>.rb</code> and <code>.so</code> have been loaded and if so short-circuit the search?</p>
<p>It would still do a search every time if only the .so is loaded (like currently), but it seems features which only exist as <code>.so</code> and not as <code>.rb</code> are rather rare.</p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=871622020-08-24T01:38:52ZDan0042 (Daniel DeLorme)
<ul></ul><p>Without the patch:</p>
<pre><code class="ruby syntaxhl" data-language="ruby"><span class="nb">require</span> <span class="s2">"digest"</span>
<span class="nb">p</span> <span class="no">Digest</span><span class="o">::</span><span class="no">SHA256</span> <span class="c1">#=> Digest::SHA256</span>
<span class="nb">p</span> <span class="no">Digest</span><span class="o">::</span><span class="no">SHA2</span> <span class="c1">#=> Digest::SHA2</span>
</code></pre>
<p>With the patch:</p>
<pre><code class="ruby syntaxhl" data-language="ruby"><span class="nb">require</span> <span class="s2">"digest"</span>
<span class="nb">p</span> <span class="no">Digest</span><span class="o">::</span><span class="no">SHA256</span> <span class="c1">#=> Digest::SHA256</span>
<span class="nb">p</span> <span class="no">Digest</span><span class="o">::</span><span class="no">SHA2</span> <span class="c1">#=> uninitialized constant Digest::SHA2</span>
</code></pre>
<p>The fix in digest.rb is simple enough:</p>
<pre><code> def self.const_missing(name) # :nodoc:
case name
when :SHA256, :SHA384, :SHA512
- lib = 'digest/sha2.so'
+ lib = 'digest/sha2.rb'
else
</code></pre> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=927302021-07-02T15:16:17Zjeremyevans0 (Jeremy Evans)merch-redmine@jeremyevans.net
<ul><li><strong>Tracker</strong> changed from <i>Bug</i> to <i>Feature</i></li><li><strong>ruby -v</strong> deleted (<del><i>ruby 2.6.3p62 (2019-04-16 revision 67580) [x86_64-linux]</i></del>)</li><li><strong>Backport</strong> deleted (<del><i>2.4: UNKNOWN, 2.5: UNKNOWN, 2.6: UNKNOWN</i></del>)</li></ul><p>This is still a performance issue in the master branch. I think it makes sense to fix the issue by using the approach recommended by <a class="user active user-mention" href="https://redmine.ruby-lang.org/users/7174">@deivid (David Rodríguez)</a> is best. In addition to being faster, is also makes the behavior for native libraries consistent with pure ruby libraries. However, because this breaks backwards compatibility, it must be considered a feature and not a bug. I've submitted a pull request to implement this feature: <a href="https://github.com/ruby/ruby/pull/4622" class="external">https://github.com/ruby/ruby/pull/4622</a>. I've also submitted a pull request to digest to fix the issue identified by <a class="user active user-mention" href="https://redmine.ruby-lang.org/users/11019">@Dan0042 (Daniel DeLorme)</a>: <a href="https://github.com/ruby/digest/pull/22" class="external">https://github.com/ruby/digest/pull/22</a>. I'll add this to the discussion list for the next developer meeting.</p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=928542021-07-10T01:20:25Zlamont (Lamont Granquist)lamont@scriptkiddie.org
<ul></ul><p>We've still been using the David Rodriguez patch with no reported issues around it for the past ~2 years or so.</p>
<p>It is likely that we don't hit the Digest issue due to the way we already have to play games with that built-in gem due to fips.</p>
<p>We also don't do rails, though, so it could certainly break something very common in that use case and we'd have never seen it.</p>
<p>(More just reporting here that we're still using it and still have no problems to report).</p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=928742021-07-12T16:07:45Znobu (Nobuyoshi Nakada)nobu@ruby-lang.org
<ul><li><strong>File</strong> <a href="/attachments/8954">0001-Sort-feature-index-arrays-by-the-priority-of-file-ty.patch</a> <a class="icon-only icon-download" title="Download" href="/attachments/download/8954/0001-Sort-feature-index-arrays-by-the-priority-of-file-ty.patch">0001-Sort-feature-index-arrays-by-the-priority-of-file-ty.patch</a> added</li><li><strong>Tracker</strong> changed from <i>Feature</i> to <i>Bug</i></li><li><strong>Backport</strong> set to <i>2.6: UNKNOWN, 2.7: REQUIRED, 3.0: REQUIRED</i></li></ul><p>The feature index arrays seems to ignore the priority of file types.</p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=929802021-07-23T19:38:17Zjeremyevans0 (Jeremy Evans)merch-redmine@jeremyevans.net
<ul></ul><p>I've reviewed @nobu's patch and think that we should go with that approach. It avoids the backwards compatibility issues with @deivid's approach while still fixing the performance issue. I submitted a pull request for it: <a href="https://github.com/ruby/ruby/pull/4674" class="external">https://github.com/ruby/ruby/pull/4674</a></p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=929842021-07-25T11:08:05Znobu (Nobuyoshi Nakada)nobu@ruby-lang.org
<ul><li><strong>Status</strong> changed from <i>Assigned</i> to <i>Closed</i></li></ul><p>Applied in changeset <a class="changeset" title="Sort feature index arrays by the priority of file types [Bug #15856] When looking for libraries ..." href="https://redmine.ruby-lang.org/projects/ruby-master/repository/git/revisions/b360588cd3cbac5fb4f004aa53a8fdc715906719">git|b360588cd3cbac5fb4f004aa53a8fdc715906719</a>.</p>
<hr>
<p>Sort feature index arrays by the priority of file types [Bug <a class="issue tracker-1 status-5 priority-4 priority-default closed" title="Bug: Performance of redundant `Kernel.require` is slow when many gems are activated (Closed)" href="https://redmine.ruby-lang.org/issues/15856">#15856</a>]</p>
<p>When looking for libraries to load with a feature name without<br>
extension, <code>.rb</code> files are given priority. However, since the<br>
feature index arrays were not in that order of priority, but in<br>
the order in which they were loaded, a lower priority extension<br>
library might be returned. In that case, the <code>.rb</code> file had to be<br>
searched for again from the <code>$LOAD_PATH</code>, resulting in poor<br>
performance.</p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=929862021-07-25T15:13:38Zdeivid (David Rodríguez)
<ul></ul><p>Thanks for working on this and coming up with a 100% backwards compatible fix! <3</p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=930732021-08-01T09:23:32Znagachika (Tomoyuki Chikanaga)nagachika00@gmail.com
<ul><li><strong>Backport</strong> changed from <i>2.6: UNKNOWN, 2.7: REQUIRED, 3.0: REQUIRED</i> to <i>2.6: UNKNOWN, 2.7: REQUIRED, 3.0: DONE</i></li></ul><p>ruby_3_0 0dbb3c15dbe9b7693ea362c94ed8939d20cba083 merged revision(s) b360588cd3cbac5fb4f004aa53a8fdc715906719.</p> Ruby master - Bug #15856: Performance of redundant `Kernel.require` is slow when many gems are activatedhttps://redmine.ruby-lang.org/issues/15856?journal_id=948752021-11-24T10:26:32Zusa (Usaku NAKAMURA)usa@garbagecollect.jp
<ul><li><strong>Backport</strong> changed from <i>2.6: UNKNOWN, 2.7: REQUIRED, 3.0: DONE</i> to <i>2.6: UNKNOWN, 2.7: DONE, 3.0: DONE</i></li></ul><p>ruby_2_7 7d4d38f8838579592e70fb04a6a2f0162fe989c2 merged revision(s) b360588cd3cbac5fb4f004aa53a8fdc715906719.</p>