Skip to content

@xaviershay /make_files.rb secret
Created

Embed URL

HTTPS clone URL

Subversion checkout URL

You can clone with
or
.
Download ZIP
`mkdir f`
10000.times do |x|
`touch f/bogus#{x}.rb`
end
require 'rubygems'
$LOAD_PATH.unshift(File.expand_path('f'))
x = 0
require 'benchmark'
Benchmark.bm do |b|
(1..5).each do |n|
b.report("#{n * 500} requires") { (n*500).times { require "bogus#{x}"; x += 1 }}
end
end
@rdp
rdp commented

did you benchmark in linux, I presume?

@xaviershay
Owner

no this was OSX. If you have a linux box handy please do test, the initial investigation I've done shows that a large component of the slowdown in 1.9.2 is algorithmic though.

@rdp
rdp commented

I guess one could use virtualbox on OS X [that's what I use typically...]

@luislavena

@xaviershay have you compared this against latest ruby trunk?

@xaviershay
Owner

I think I did and it was roughly the same. I will add it to my graph.

@luislavena

Are you sure? Asking this because the other gist you gave to this issue here: https://gist.github.com/950154

Is still against 1.9.2...

@xaviershay
Owner

So 1.9.3 is twice as bad as 1.9.2 again....

@luislavena

I see your bench script, but what is missing is the generator for the blank files. Please add it and I'll take a look to help you out debug this.

This sucks, but I was not able to reproduce this on Windows, or I least I think that...

@xaviershay
Owner

Sorry my bad, I have added make_files.rb to the gist. Of interest, jruby sucks somewhat also. RBX isn't great but at least it's somewhat linear:

@headius

The increasing time in 1.9.3 and JRuby 1.6.1 may be partly due to the case insensitive require search. In order to prevent require 'date' and require 'DATE' requiring the same file twice on a case-insensitive filesystem, both JRuby and 1.9.3 will treat it as the same filename.

We definitely will want to look into this in JRuby, since there's clear evidence that something is nonlinear over time wrt require speed.

@xaviershay
Owner

@headius if no one is already looking at it in jruby, I plan to jump ship and dive in after I've done what I can with MRI.

@headius

There's been some recent pull requests with require improvements...those are only landed on master (and maybe the 1.6 branch). I think they improve things in the neighborhood of 10%.

If you do start looking into it, there's a couple JRuby flags that will help:

-Xdebug.loadService=true turns on logging of what paths the load/require process is searching, along with what path it finally uses to load a resource. It will show how many searches are being done; we do more than 1.9 because we search for both .rb and .class (compiled script) on the filesystem...plus we search JVM classloader resources. That's likely why load/require file searches take longer in JRuby.

-Xdebug.loadService.timing=true will log how long files take to require/load, including child requires/loads. This mostly measures the time for individual files and how long they take to parse, but it can sometimes show file searching costs too (especially for classloader-located resources).

Let me know when you start poking around and I'll do what I can to help.

@xaviershay
Owner

For those playing along at home, here is the latest progress update: http://redmine.ruby-lang.org/issues/show/3924

Turns out there's already a case-insensitive hash in MRI (st.h) which certainly made things easier.

(note this graph is versus 1.8.7 over a larger number of files)

@headius

I'm going to look into improving the LOADED_FEATURES array as well, probably by making it use a case-insensitive Set or Map for searches internally. I see now that's likely a primary bottleneck when lots of features are getting loaded, due to the O(N) search every time.

@chaffeqa

Well I wasn't able to open an issue on your ruby fork, but I ran your blog post scripts and got an error when trying to run rails s --debug (so using ruby-debug19)

Error:

/home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/activesupport/lib/active_support/dependencies.rb:236:in `require': /home/jenny/.rvm/gems/ruby-head-patched/gems/ruby-debug-base19-0.11.25/lib/ruby_debug.so: undefined symbol: ruby_thread_data_type - /home/jenny/.rvm/gems/ruby-head-patched/gems/ruby-debug-base19-0.11.25/lib/ruby_debug.so (LoadError)
from /home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/activesupport/lib/active_support/dependencies.rb:236:in `block in require'
from /home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/activesupport/lib/active_support/dependencies.rb:222:in `block in load_dependency'
from /home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/activesupport/lib/active_support/dependencies.rb:616:in `new_constants_in'
from /home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/activesupport/lib/active_support/dependencies.rb:222:in `load_dependency'
from /home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/activesupport/lib/active_support/dependencies.rb:236:in `require'
from /home/jenny/.rvm/gems/ruby-head-patched/gems/ruby-debug-base19-0.11.25/lib/ruby-debug-base.rb:1:in `<top (required)>'
from /home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/activesupport/lib/active_support/dependencies.rb:236:in `require'
from /home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/activesupport/lib/active_support/dependencies.rb:236:in `block in require'
from /home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/activesupport/lib/active_support/dependencies.rb:222:in `block in load_dependency'
from /home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/activesupport/lib/active_support/dependencies.rb:616:in `new_constants_in'
from /home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/activesupport/lib/active_support/dependencies.rb:222:in `load_dependency'
from /home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/activesupport/lib/active_support/dependencies.rb:236:in `require'
from /home/jenny/.rvm/gems/ruby-head-patched/gems/ruby-debug19-0.11.6/cli/ruby-debug.rb:5:in `<top (required)>'
from /home/jenny/.rvm/gems/ruby-head-patched/gems/bundler-1.0.14/lib/bundler/runtime.rb:68:in `require'
from /home/jenny/.rvm/gems/ruby-head-patched/gems/bundler-1.0.14/lib/bundler/runtime.rb:68:in `block (2 levels) in require'
from /home/jenny/.rvm/gems/ruby-head-patched/gems/bundler-1.0.14/lib/bundler/runtime.rb:66:in `each'
from /home/jenny/.rvm/gems/ruby-head-patched/gems/bundler-1.0.14/lib/bundler/runtime.rb:66:in `block in require'
from /home/jenny/.rvm/gems/ruby-head-patched/gems/bundler-1.0.14/lib/bundler/runtime.rb:55:in `each'
from /home/jenny/.rvm/gems/ruby-head-patched/gems/bundler-1.0.14/lib/bundler/runtime.rb:55:in `require'
from /home/jenny/.rvm/gems/ruby-head-patched/gems/bundler-1.0.14/lib/bundler.rb:120:in `require'
from /home/jenny/Projects/GoldenCMS/config/application.rb:7:in `<top (required)>'
from /home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/railties/lib/rails/commands.rb:56:in `require'
from /home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/railties/lib/rails/commands.rb:56:in `block in <top (required)>'
from /home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/railties/lib/rails/commands.rb:53:in `tap'
from /home/jenny/.rvm/gems/ruby-head-patched/bundler/gems/rails-62d5ef0c17b4/railties/lib/rails/commands.rb:53:in `<top (required)>'
from script/rails:6:in `require'
from script/rails:6:in `<main>'

(Same error occurs just running 'rails s')

At this point I wish I was more knowledgeable in ruby, but I'm afraid I don't have the time at the moment to dive into the issue. Maybe later today after I get some work done.

As a side note, this same rails project runs fine using:

  • MRI 1.9.2
  • rails3.1
  • ruby-debug19
  • ect...

Only differences in environment to trigger the code:

  • MRI-1.9.2 <--> MRI-1.9.3
  • Your patch
@xaviershay
Owner

urgh that doesn't look friendly. Are you able to try on 1.9.3 without my patch?

Thanks for trying it out!

@chaffeqa

Ah yep... the same error occurred using straight 1.9.3dev.
Well in a strange sense I'm pumped your patch still looks good! Thanks for all the work your putting into this!

Cheers!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Something went wrong with that request. Please try again.