Bug #11448: Requiring a given library may take 23x longer depending on `require` context

• Status: Closed
• Assignee: -
• Target version: -
• ruby -v: ruby 2.2.2p95 (2015-04-13 revision 50295) [x86_64-darwin14]
• Backport: 2.0.0: UNKNOWN, 2.1: UNKNOWN, 2.2: UNKNOWN

[rafBM (Rafaël Blais Masson)]

I was trying to narrow down the longest things to require during Rails boot when I stumbled on this.

Add two lines in securerandom.rb in order to output the time taken to require 'openssl':

 # -*- coding: us-ascii -*-
 begin
+  start = Time.now
   require 'openssl'
+  puts Time.now - start
 rescue LoadError
 end

 # == Secure random number generator interface.
 # ...

Now run a script containing just this:

require 'securerandom'

Average output: 0.038829

But run a similar script that requires a higher-level library, like:

require 'action_mailer'

Average output: 0.907959

This still measures the time taken to require 'openssl' only. Why is it 23x times slower? Because it is nested within other require calls? When requiring action_mailer, this is the tree of files required to get to securerandom:

require 'action_mailer'
  require 'abstract_controller'
    require 'active_support/rails'
      require 'active_support/deprecation'
        require 'active_support/deprecation/behaviors'
          require 'active_support/notifications'
            require 'active_support/notifications/instrumenter'
              require 'securerandom'

When starting one level down, time to require 'openssl' is cut in half:

require 'abstract_controller'

Average output: 0.465274

[Hanmac (Hans Mackowiak)]

i think that has something to do that each required gem does increase the $LOAD_PATH,
and how longer the load path is, it takes more time to require something.

that what i think does explain it. (its sad but i dont know a better way)

hm i dont know, but would using require_relative like inside of active_support reduce the average output? or does it maybe even increase it?

[jeremyevans0 (Jeremy Evans)]

• Status changed from Open to Closed

I don't think this is a significant issue with current Ruby, though it was certainly a bigger issue in previous versions. From some testing:

$ ruby22 -r active_record -e "t = Time.now; require 'English'; p(Time.now - t)" 
0.004071895
$ ruby22 -e "t = Time.now; require 'English'; p(Time.now - t)" 
0.000901009

$ ruby27 -r active_record -e "t = Time.now; require 'English'; p(Time.now - t)" 
0.00102763
$ ruby27 -e "t = Time.now; require 'English'; p(Time.now - t)"                  
0.000822299

So on my system, it was about a 4.5x difference in 2.2, but is only about a 25% difference in 2.7. There will always be at least a small difference due to the fact that Ruby needs to do a linear search of the load path, and requiring the active_record library in this case almost doubles the size of the load path. So I think this can be closed.