Robot Has No Heart

Xavier Shay blogs here

A robot that does not have a heart

Speeding up Rails startup time

In which I provide easy instructions to try a new patch that drastically improves the start up time of Ruby applications, in the hope that with wide support it will be merged into the upcoming 1.9.3 release. Skip to the bottom for instructions, or keep reading for the narrative.

UPDATE: If you have trouble installing, grab a recent copy of rvm: rvm get head.

Background

Recent releases of MRI Ruby have introduced some fairly major performance regressions when requiring files:

For reference, our medium-sized Rails application requires around 2200 files &emdash; off the right-hand side of this graph. This is problematic. On 1.9.2 it takes 20s to start up, on 1.9.3 it takes 46s. Both are far too long.

There are a few reasons for this, but the core of the problem is the basic algorithm which looks something like this:

1
2
3
4
5
6
7
def require(file)
  $loaded.each do |x|
    return false if x == file
  end
  load(file)
  $loaded << file
end

That loop is no good, and gets worse the more files you have required. I have written a patch for 1.9.3 which changes this algorithm to:

1
2
3
4
5
def require(file)
  return false if $loaded[file] 
  load(file)
  $loaded[file] = true
end

That gives you a performance curve that looks like this:

Much nicer.

That’s just a synthetic benchmark, but it works in the real world too. My main Rails application now loads in a mite over 10s, down from 20s it was taking on 1.9.2. A blank Rails app loads in 1.1s, which is even faster than 1.8.7.

Getting the fix

Here is how you can try out my patch right now in just ten minutes using RVM.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
# First get a baseline measurement
cd /your/rails/app
time script/rails runner "puts 1"

# Install a patched ruby
curl https://gist.github.com/raw/996418/e2b346fbadeed458506fc69ca213ad96d1d08c3e/require-performance-fix-r31758.patch > /tmp/require-performance-fix.patch
rvm install ruby-head --patch /tmp/require-performance-fix.patch -n patched
# ... get a cup of tea, this took about 8 minutes on my MBP

# Get a new measurement
cd /your/rails/app
rvm use ruby-head-patched
gem install bundler --no-rdoc --no-ri
bundle
time script/rails runner "puts 1"

How you can help

I need a lot more eyeballs on this patch before it can be considered for merging into trunk. I would really appreciate any of the following:

Next steps

I imagine there will be a bit more work to get this into Ruby 1.9.3, but after that this is just the first step of many to try and speed up the time Rails takes to start up. Bundler and RubyGems still spend a lot of time doing … something, which I want to investigate. I also want to port these changes over to JRuby which has similar issues (Rubinius isn’t quite as fast out of the gate, but does not degrade exponentially so would not benefit from this patch).

Thank you for your time.

  1. Scott Watermasysk says:

    Here are my results:

    1.9.2-p180
    script/rails runner "puts 1" 4.58s user 0.74s system 89% cpu 5.938 total

    1.9.2 head w/your patch
    script/rails runner "puts 1" 2.59s user 0.38s system 99% cpu 2.974 total

    I also ran my specs against it:

    1.9.2-p180
    rspec spec 15.19s user 1.09s system 99% cpu 16.420 total

    1.9.2 head w/your patch
    rspec spec 10.97s user 0.66s system 98% cpu 11.764 total

    So far it looks like a big improvement. It was nice to see results form the spec run almost immediately.

    The only odd thing I saw was out put about "missing psych". Everything still worked.

    Thanks,
    @scottw

  2. David says:

    Large rails 2.3.11 project on my MBP

    ruby-1.9.2-p136

    1
    2
    3
    
    real        0m15.298s
    user        0m7.126s
    sys        0m1.418s
    

    ruby-head with patch
    1
    2
    3
    
    real        0m7.659s
    user        0m6.515s
    sys        0m1.127s
    

    Nice!

  3. Kain says:

    rvm install ruby-head for some reason is trying to get 1.8.7 installed for me.

  4. Collin Miller says:

    Anybody have trouble installing libxml-ruby with this patch?

    gem_make.out with patch

    1
    2
    3
    
    /Users/collin/.rvm/rubies/ruby-head/bin/ruby extconf.rb 
    extconf.rb:6: stack level too deep (SystemStackError)
    /Users/collin/.rvm/gems/ruby-head/gems/libxml-ruby-1.1.4/ext/libxml/gem_make.out (END) 
    

  5. marcus derencius says:

    My results:

    ruby 1.9.2p180 (2011-02-18 revision 30909) [x86_64-darwin10.6.0]
    script/rails runner "puts 1" 2,61s user 0,49s system 66% cpu 4,651 total

    ruby 1.9.3dev (2011-05-29 trunk 31763) [x86_64-darwin10.6.0]
    script/rails runner "puts 1" 1,02s user 0,17s system 49% cpu 2,428 total

    that's cool.
    thanks!

  6. marcus derencius says:

    @kain probably you need to update your rvm. "rvm get head"

  7. Tom says:

    Rails 3.1.0.rc2, MBP 2.66 Core i7

    command: 'rake'

    Ruby 1.9.2p0

    1
    2
    3
    
    real        0m31.357s
    user        0m25.420s
    sys        0m3.833s
    

    Ruby head with patch

    1
    2
    3
    
    real        0m14.633s
    user        0m12.441s
    sys        0m2.113s
    

  8. dude says:

    This wont work for me.

    $ rvm install ruby-head --patch /tmp/require-performance-fix.patch
    Installing Ruby from source to: /Users/myuser/.rvm/rubies/ruby-head, this may take a while depending on your cpu(s)...

    ruby-head - #fetching
    HEAD is now at e15b3c8 * test/net/http/utils.rb (TestNetHTTPUtils#teardown): add nil check.
    From https://github.com/ruby/ruby
    * branch trunk -> FETCH_HEAD
    Already up-to-date.
    Copying from repo to src path...
    Applying patch '/tmp/require-performance-fix.patch' (located at //tmp/require-performance-fix.patch)
    Running autoconf
    ERROR: Skipping configure step, 'configure' does not exist, did autoconf not run successfully?
    ruby-head - #compiling
    ERROR: Error running 'make ', please read /Users/funduk/.rvm/log/ruby-head/make.log
    ERROR: There has been an error while running make. Halting the installation.

    Using rvm 1.6.16, ruby 1.9.2p180 (from rvm).

  9. Joe Van Dyk says:

    Dude, I get the same. :(

  10. Evan Owen says:

    I'm getting the same error:

    ...
    Running autoconf
    ERROR: Skipping configure step, 'configure' does not exist, did autoconf not run successfully?"
    ...

    Also using rvm 1.6.16.

  11. Joe Van Dyk says:

    Wayne just pushed out an update to rvm that fixes the install problem.

    https://github.com/wayneeseguin/rvm/commit/572ecc1ba87b15ca59ea8cca0309dbab80e98bc8

    get it by doing 'rvm get head'.

  12. Joe Van Dyk says:

    By the way, if you want a benchmark application, I created https://github.com/joevandyk/slow-rails for just this purpose.

  13. Joe Van Dyk says:

    Link: https://github.com/joevandyk/slow-rails

  14. Joe Van Dyk says:

    On my slow-rails application, ruby-head w/ patch runs 'bundle exec rake' in 10 seconds.

    1.9.2 takes 15.

    Ruby 1.8.7 REE takes 7.7 seconds.

  15. Marc Howell says:

    On a fresh project, just including the thinking-sphinx gem, I get this

    /home/sapient/.rvm/gems/ruby-head/gems/activesupport-3.0.7/lib/active_support/dependencies.rb:239:in `require': cannot load such file -- riddle/0.9.9 (LoadError)

    It does not happen on 1.9.2, but I am not sure if it happens on an unpatched 1.9.3.

  16. Brian Rose says:

    This patch improved startup time from 8 seconds to 4. You're my hero.

  17. Evan Owen says:

    I'm getting some require load errors as well, with the grit gem. This worked fine without the patch:

    ruby-head :001 > require 'rubygems'
    => false
    ruby-head :002 > require 'grit'
    LoadError: cannot load such file -- grit/ruby1.9
    from /Users/kainosnoema/.rvm/rubies/ruby-head/lib/ruby/site_ruby/1.9.1/rubygems/custom_require.rb:58:in `require'
    from /Users/kainosnoema/.rvm/rubies/ruby-head/lib/ruby/site_ruby/1.9.1/rubygems/custom_require.rb:58:in `rescue in require'
    from /Users/kainosnoema/.rvm/rubies/ruby-head/lib/ruby/site_ruby/1.9.1/rubygems/custom_require.rb:35:in `require'
    from /Users/kainosnoema/.rvm/gems/ruby-head/gems/grit-2.4.1/lib/grit.rb:28:in `<top (required)>'
    from /Users/kainosnoema/.rvm/rubies/ruby-head/lib/ruby/site_ruby/1.9.1/rubygems/custom_require.rb:58:in `require'
    from /Users/kainosnoema/.rvm/rubies/ruby-head/lib/ruby/site_ruby/1.9.1/rubygems/custom_require.rb:58:in `rescue in require'
    from /Users/kainosnoema/.rvm/rubies/ruby-head/lib/ruby/site_ruby/1.9.1/rubygems/custom_require.rb:35:in `require'
    from (irb):2
    from /Users/kainosnoema/.rvm/rubies/ruby-head/bin/irb:16:in `<main>'

  18. Evan Owen says:

    From looking at the load errors above, it seems like requires with numerals in them are causing problems. Does that seem likely?

  19. Robb Kidd says:

    ruby 1.9.2 p180

    1
    2
    
    user: 8.96
    sys: 2.90
    

    ruby-head (e15b3c8) + patch
    1
    2
    
    user: 4.30
    sys:  1.71
    

  20. thecatwasnot says:

    Marc, I see the same thing using thinking-sphinx, just tried to run it on unpatched ruby-head and ffi is giving me fits instead, would like to hear if you get it running.

  21. kpolitowicz says:

    Trying to get the patch working for 1.9.2-head - but it's been years since I last looked at C code - any help appreciated.

    @Scott Watermasysk: did you run 1.9.2-head or ruby-head? If the former, could you please gist your patch version?

  22. kpolitowicz says:

    | Name | Lines | LOC | Classes | Methods | M/C | LOC/M |
    +----------------------+-------+-------+---------+---------+-----+-------+
    | Total | 20810 | 14099 | 57 | 459 | 8 | 28 |
    +----------------------+-------+-------+---------+---------+-----+-------+

    1.9.2-p180:

    real 0m7.709s
    user 0m6.566s
    sys 0m1.025s

    ruby-head w/ patch:

    real 0m5.304s
    user 0m4.790s
    sys 0m0.450s

  23. Marc Howell says:

    thecatwasnot, I'm checking out the 1.9.3 source now, trying to figure out what exactly is causing this, no luck so far, but I will keep looking.

  24. Evan Owen says:

    Ok, I did a little investigating and discovered the the issue with both the thinking-spinx and grit gems is that they're requiring files that have multiple dots (ie. ruby1.9.rb, 0.9.9.rb).

    The patch wasn't written to handle that case, so I made a simple change and posted an updated patch here: http://bit.ly/kZsurg

    It seems to work fine now for all the gems we user in our project.

  25. Evan Owen says:

    ruby-1.9.2-p180:

    real 0m29.502s
    user 0m19.920s
    sys 0m2.714s

    ruby-head w/ patch updated for multiple dots (http://bit.ly/kZsurg):

    real 0m15.205s
    user 0m8.838s
    sys 0m1.630s

  26. thecatwasnot says:

    And finally, after using Evan's modified patch, and fighting with psych I got it going...

    rails 1.9.2-p136
    ∴ time script/rails runner "puts 1"
    1

    real 0m43.888s
    user 0m33.738s
    sys 0m2.012s

    ruby-head with patch http://bit.ly/kZsurg
    ∴ time script/rails runner "puts 1"
    1

    real 0m20.273s
    user 0m16.989s
    sys 0m1.324s

    Have to say, that's really cool :D

  27. fred dealmeida says:

    I wonder how this compares with Rbx? Has anyone tested for this yet?

  28. Xavier Shay says:

    Wow everyone, thanks so much for the response.

    I have integrated the fix for grit and friends, and update my post/patch. Thanks Evan! I also added a test for it.

    Colin: libxml-ruby is broken on ruby-head without my patch. Still an issue, but out of scope for now.

  29. Xavier Shay says:

    Fred, there's a graph with rbx on it on this gist

    Maybe I was premature in saying this patch would not be helpful...

  30. Scott Watermasysk says:

    @kpolitowicz - sorry, that was a mistype. I meant ruby-head not 1.9.2 head.

  31. Nemo says:

    Rails 3 - default stack

    Without patch:
    2.96s user 0.44s system 50% cpu 6.763 total

    With patch:
    1.08s user 0.12s system 98% cpu 1.209 total

    Woo hoo! Thanks.

  32. Nemo says:

    Couple errors:

    rvm install ruby-head --patch /tmp/require-performance-fix.patch -n patched
    Unrecognized command line argument: '-n' ( see: 'rvm usage' )

    /home/.rvm/scripts/manage: line 1382: bin/mkdir: No such file or directory

  33. Dan Kubb says:

    @xshay: Do you have the source for the synthetic benchmark available? Everyone's Rails apps are going to vary wildly, but having something consistent to use as a baseline would be helpful in testing.

  34. Jack Bean says:

    Ran into an error:

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    16
    17
    18
    19
    20
    21
    22
    23
    24
    25
    26
    27
    28
    29
    30
    31
    32
    33
    34
    35
    36
    37
    38
    39
    40
    41
    42
    43
    44
    45
    46
    47
    48
    49
    50
    51
    52
    
    Installing ffi (1.0.6) with native extensions /home/.rvm/rubies/ruby-head/lib/ruby/site_ruby/1.9.1/rubygems/installer.rb:543:in `rescue in block in build_extensions': ERROR: Failed to build gem native extension. (Gem::Installer::ExtensionBuildError)
    
            /home/.rvm/rubies/ruby-head/bin/ruby extconf.rb 
    checking for ffi_call() in -lffi... yes
    checking for ffi_prep_closure()... yes
    checking for ffi_raw_call()... yes
    checking for ffi_prep_raw_closure()... yes
    checking for rb_thread_blocking_region()... yes
    checking for ruby_thread_has_gvl_p()... yes
    checking for ruby_native_thread_p()... yes
    checking for rb_thread_call_with_gvl()... yes
    creating extconf.h
    creating Makefile
    
    make
    compiling DataConverter.c
    compiling ClosurePool.c
    compiling MappedType.c
    compiling Buffer.c
    compiling ffi.c
    compiling Variadic.c
    Variadic.c: In function ‘variadic_invoke’:
    Variadic.c:204:13: warning: format ‘%x’ expects type ‘unsigned int’, but argument 3 has type ‘struct Type *’
    compiling Type.c
    compiling Thread.c
    compiling ArrayType.c
    compiling Pointer.c
    compiling Function.c
    compiling Platform.c
    compiling StructByValue.c
    compiling MemoryPointer.c
    compiling Types.c
    compiling AbstractMemory.c
    compiling Call.c
    compiling Struct.c
    Struct.c: In function ‘struct_set_pointer’:
    Struct.c:315:36: warning: comparison between signed and unsigned integer expressions
    Struct.c: In function ‘inline_array_offset’:
    Struct.c:452:28: warning: comparison between signed and unsigned integer expressions
    Struct.c: In function ‘inline_array_each’:
    Struct.c:542:19: warning: comparison between signed and unsigned integer expressions
    Struct.c: In function ‘inline_array_to_a’:
    Struct.c:560:19: warning: comparison between signed and unsigned integer expressions
    compiling StructByReference.c
    compiling LastError.c
    compiling MethodHandle.c
    compiling DynamicLibrary.c
    compiling FunctionInfo.c
    compiling StructLayout.c
    StructLayout.c: In function ‘struct_layout_initialize’:
    StructLayout.c:377:9: error: lvalue required as left operand of assignment
    make: *** [StructLayout.o] Error 1
    

  35. thecatwasnot says:

    Jack, that was the error I was having trouble with too, but it's the same on ruby-head without the patch.

  36. chendo says:

    Small Rails 3.x project.

    1.9.2

    rspec spec -I.: 5.769s total, 5.03s user, 0.54s system, 96% cpu
    script/rails runner "puts 1": 2.835s total, 2.49s user, 0.34s system, 99% cpu
    head-patched

    rspec spec -I.: 3.475s total, 3.02s user, 0.29s system, 95% cpu
    script/rails runner "puts 1": 1.688s total, 1.50s user, 0.18s system, 99% cpu

    Definitely a boost in performance, really keen to see this in the next ruby.

  37. Al Brown says:

    Great work.

  38. Xavier Shay says:

    Dan: https://gist.github.com/c8d0d422a9203e1fe492

    I don't think results for different people on this woud be interesting though ... it's just an easy way to show the algorithmic difference.

  39. David Schovanec says:

    It works for me.

    real 0m21.900s
    user 0m6.554s
    sys 0m1.707s

    against

    real 0m5.236s
    user 0m3.190s
    sys 0m0.517s

    4 times faster is more than fine :)

  40. Jon says:

    Great post!


    ruby-1.9.2-p180:

    real 0m4.576s
    user 0m3.612s
    sys 0m0.639s


    ruby-head w/ patch updated (but getting warnings about missing psych and "use RbConfig instead of obsolete and deprecated Config"):

    real 0m2.688s
    user 0m2.394s
    sys 0m0.247s

  41. Gosha says:

    Maybe my solution look nicer? Note on the 2nd line.

    def require(file)
    return false if $loaded.include? file
    load(file)
    $loaded[file] = true
    end

  42. bartocc says:

    Hi, here are my results

    1.9.2-p180 - script/rails runner "puts 1"

    real 0m12.236s
    user 0m10.078s
    sys 0m1.582s

    1.9.2 head w/your patch - script/rails runner "puts 1"

    real 0m8.643s
    user 0m7.241s
    sys 0m0.955s

    @bartocc

  43. mech says:

    Redcloth appear not working for the patched Ruby

    Installing RedCloth (4.2.7) with native extensions /Users/mech/.rvm/rubies/ruby-head-patched/lib/ruby/site_ruby/1.9.1/rubygems/installer.rb:533:in `rescue in block in build_extensions': ERROR: Failed to build gem native extension. (Gem::Installer::ExtensionBuildError)

    /Users/mech/.rvm/rubies/ruby-head-patched/bin/ruby extconf.rb
    checking for main() in -lc... yes
    creating Makefile

    make
    compiling redcloth_attributes.c
    cc1: warnings being treated as errors
    ragel/redcloth_attributes.c.rl: In function ‘redcloth_attributes’:
    ragel/redcloth_attributes.c.rl:45: warning: ISO C90 forbids mixed declarations and code
    ragel/redcloth_attributes.c.rl: In function ‘redcloth_link_attributes’:
    ragel/redcloth_attributes.c.rl:54: warning: ISO C90 forbids mixed declarations and code
    make: *** [redcloth_attributes.o] Error 1


    Gem files will remain installed in /Users/mech/.rvm/gems/ruby-head-patched/gems/RedCloth-4.2.7 for inspection.
    Results logged to /Users/mech/.rvm/gems/ruby-head-patched/gems/RedCloth-4.2.7/ext/redcloth_scan/gem_make.out
    from /Users/mech/.rvm/rubies/ruby-head-patched/lib/ruby/site_ruby/1.9.1/rubygems/installer.rb:511:in `block in build_extensions'
    from /Users/mech/.rvm/rubies/ruby-head-patched/lib/ruby/site_ruby/1.9.1/rubygems/installer.rb:486:in `each'
    from /Users/mech/.rvm/rubies/ruby-head-patched/lib/ruby/site_ruby/1.9.1/rubygems/installer.rb:486:in `build_extensions'
    from /Users/mech/.rvm/rubies/ruby-head-patched/lib/ruby/site_ruby/1.9.1/rubygems/installer.rb:159:in `install'
    from /Users/mech/.rvm/gems/ruby-head-patched/gems/bundler-1.0.14/lib/bundler/source.rb:101:in `block in install'
    from /Users/mech/.rvm/gems/ruby-head-patched/gems/bundler-1.0.14/lib/bundler/rubygems_integration.rb:78:in `preserve_paths'
    from /Users/mech/.rvm/gems/rub

  44. Bruno Michel says:

    Here's the results for my website <a href="https://github.com/nono/linuxfr.org">LinuxFr.org</a>:

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    
    % ruby -v
    ruby 1.9.2p180 (2011-02-18 revision 30909) [i686-linux]
    % time rspec spec
    rspec spec  39,37s user 2,20s system 93% cpu 44,397 total
    % time script/rails runner "puts 1"
    script/rails runner "puts 1"  20,36s user 1,41s system 99% cpu 21,805 total
    
    % rvm use ruby-head-patched
    % ruby -v
    ruby 1.9.3dev (2011-05-29 trunk 31779) [i686-linux]
    % time rspec spec
    rspec spec  20,12s user 1,54s system 88% cpu 24,357 total
    % time script/rails runner "puts 1"
    script/rails runner "puts 1"  7,17s user 0,89s system 99% cpu 8,081 total
    

    Thanks for your work.

  45. Thibaud Guillaume-Gentil says:

    Rails 3.0.7 (descent application)

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    
    → ruby -v
    ruby 1.9.2p180 (2011-02-18 revision 30909) [x86_64-darwin10.7.0]
    → time script/rails runner "puts 1"
    real        0m28.074s
    user        0m23.813s
    sys        0m3.251s
    
    → rvm use ruby-head-patched
    → ruby -v
    ruby 1.9.3dev (2011-05-29 trunk 31779) [x86_64-darwin10.7.0]
    → time script/rails runner "puts 1"
    real        0m13.085s
    user        0m10.809s
    sys        0m2.046s
    

    more than 50% boost, awesome! Thanks

  46. Paul Annesley says:

    Nice work!

    To compare apples to apples (rather than apples to ruby-1.9.2-p180) I built ruby-head from source with and without your patch, installed all gems etc, and compared my Rails 3.0.7 app as a median of 10 runs of "rails runner nil".


    ruby-head @ a3ffe969

    1
    2
    3
    
    Unpatched: 13.9155 sec
    Patched: 8.8755 sec
    Improvement: 36.21%
    

    Win :)

  47. Lorenz says:

    ruby 1.9.2p180: 13.523s
    ruby 1.9.3dev patched: 7.165s

    Thank you!

  48. iHiD says:

    Anyone got a solution with the libxml issue? xshay - Can I apply the patch to 1.9.2, rather than head, or is the patch 1.9.3 specific? If so, would that still be a useful benchmark?

  49. David Burrows says:

    Rails 3.0.6 app, pretty consistent results of ~ 50% load time of 1.9.2p180

    1
    2
    3
    4
    5
    6
    7
    8
    9
    
    ruby 1.9.2p180 (2011-02-18 revision 30909) [x86_64-darwin10.7.0]
    real        0m8.353s
    user        0m7.493s
    sys        0m0.854s
    
    ruby 1.9.3dev (2011-05-29 trunk 31779) [x86_64-darwin10.7.0]
    real        0m4.503s
    user        0m4.007s
    sys        0m0.432s
    

  50. Adam says:

    m/.

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    16
    17
    18
    
    $ time script/rails runner "puts 1"
    1
    
    real    0m12.985s
    user    0m11.220s
    sys    0m1.538s
    
    
    $ time script/rails runner "puts 1"
    /Users/adam/.rvm/rubies/ruby-head-patched/lib/ruby/1.9.1/yaml.rb:33:in `<top (required)>':
    It seems your ruby installation is missing psych (for YAML output).
    To eliminate this warning, please install libyaml and reinstall your ruby.
    /Users/adam/.rvm/gems/ruby-head-patched/gems/rake-0.8.7/lib/rake/alt_system.rb:32: Use RbConfig instead of obsolete and deprecated Config.
    1
    
    real    0m7.885s
    user    0m6.754s
    sys    0m0.875s
    

  51. Adam says:

    m/.

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    16
    17
    18
    
    $ time script/rails runner "puts 1"
    1
    
    real    0m12.985s
    user    0m11.220s
    sys    0m1.538s
    
    
    $ time script/rails runner "puts 1"
    /Users/adam/.rvm/rubies/ruby-head-patched/lib/ruby/1.9.1/yaml.rb:33:in `<top (required)>':
    It seems your ruby installation is missing psych (for YAML output).
    To eliminate this warning, please install libyaml and reinstall your ruby.
    /Users/adam/.rvm/gems/ruby-head-patched/gems/rake-0.8.7/lib/rake/alt_system.rb:32: Use RbConfig instead of obsolete and deprecated Config.
    1
    
    real    0m7.885s
    user    0m6.754s
    sys    0m0.875s
    

  52. Adam says:

    m/.

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    16
    17
    18
    
    $ time script/rails runner "puts 1"
    1
    
    real    0m12.985s
    user    0m11.220s
    sys    0m1.538s
    
    
    $ time script/rails runner "puts 1"
    /Users/adam/.rvm/rubies/ruby-head-patched/lib/ruby/1.9.1/yaml.rb:33:in `<top (required)>':
    It seems your ruby installation is missing psych (for YAML output).
    To eliminate this warning, please install libyaml and reinstall your ruby.
    /Users/adam/.rvm/gems/ruby-head-patched/gems/rake-0.8.7/lib/rake/alt_system.rb:32: Use RbConfig instead of obsolete and deprecated Config.
    1
    
    real    0m7.885s
    user    0m6.754s
    sys    0m0.875s
    

  53. James West says:

    Had a bit of a headache getting the patch to install,
    Firstly I had an error with Bison "bison is not available in your path."
    This was fixed with a sudo apt-get install bison.
    Then another issue "ERROR: rvm requires autoreconf to install the selected ruby interpreter however autoreconf was not found in the PATH.".
    This was fixed with
    sudo apt-get install autoconf

    So my results on a 3.0.8.rc1 app are
    .rvm/gems/ruby-1.8.7-p302
    time script/rails runner "puts 1"
    1

    real 0m2.675s
    user 0m2.152s
    sys 0m0.520s

    Then
    .rvm/gems/ruby-1.9.2-p180
    time script/rails runner "puts 2"
    2

    real 0m10.309s
    user 0m9.757s
    sys 0m0.560s

    And finally
    time script/rails runner "puts 3"
    .rvm/rubies/ruby-head-patched/lib/ruby/1.9.1/yaml.rb:33:in `<top (required)>':
    It seems your ruby installation is missing psych (for YAML output).
    To eliminate this warning, please install libyaml and reinstall your ruby.
    3

    real 0m3.272s
    user 0m3.044s
    sys 0m0.228s

    I'm not sure what influence that warning has, and I'm unable to get rid of it so don't take my figures for the patched version as gospel

    I fully intend to stay on 1.8.7 for the time being in order to stay as close to the production environment as possible which uses REE with 1.8.7

    Hope you find this usefull

  54. Rodrigo Rosenfeld Rosas says:

    rails new empty; cd empty; bundle; time rails runner 'puts 1'

    Ruby 1.9.2-p180: real: 0m1.845s, user: 0m1.244s, sys: 0m0.176s

    Ruby 1.9.3-dev: real: 0m1.092s, user: 0m1.044s, sys: 0m0.044s

    Ruby 1.9.3-dev-patched: real: 0m0.773s, user: 0m0.692s, sys: 0m0.080s

    Thanks for your effort!

    @Kain: I faced the same problem. It seems like a bug in RVM. I tried installing 1.8.7 once but didn't finish due to a issue with current Ruby and Debian unstable. When I tried installing ruby-head it was resolving to 1.8.7. Then I decided to manually patch Ruby 1.8.7 and finished installing it. After that ruby-head was working again. Try installing 1.8.7 first.

  55. Adam says:

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    16
    17
    18
    
    $ time script/rails runner "puts 1"
    1
    
    real    0m12.985s
    user    0m11.220s
    sys    0m1.538s
    
    
    $ time script/rails runner "puts 1"
    /Users/adam/.rvm/rubies/ruby-head-patched/lib/ruby/1.9.1/yaml.rb:33:in `<top (required)>':
    It seems your ruby installation is missing psych (for YAML output).
    To eliminate this warning, please install libyaml and reinstall your ruby.
    /Users/adam/.rvm/gems/ruby-head-patched/gems/rake-0.8.7/lib/rake/alt_system.rb:32: Use RbConfig instead of obsolete and deprecated Config.
    1
    
    real    0m7.885s
    user    0m6.754s
    sys    0m0.875s
    

  56. kpolitowicz says:

    @thecatwasnot: ffi-1.0.9 seems to work fine with ruby-head

    Tested bigger app this time:


    +----------------------+-------+-------+---------+---------+-----+-------+
    | Name | Lines | LOC | Classes | Methods | M/C | LOC/M |
    +----------------------+-------+-------+---------+---------+-----+-------+
    | Total | 10713 | 7966 | 121 | 557 | 4 | 12 |
    +----------------------+-------+-------+---------+---------+-----+-------+

    went down from ~17s to 9s. Awesome!

  57. David Backéus says:

    Without patch

    1
    2
    3
    
    real        0m9.257s
    user        0m7.982s
    sys        0m0.938s
    

    With patch
    1
    2
    3
    
    real        0m5.441s
    user        0m4.936s
    sys        0m0.497s
    

    Amazing stuff!

  58. Dan Hixon says:

    So excited to try this but it looks like I'm having issues with ffi. Any help would be appreciated!

    1
    2
    3
    4
    5
    6
    
    Installing ffi (0.6.3) with native extensions /Users/danhixon/.rvm/rubies/ruby-head-patched/lib/ruby/site_ruby/1.9.1/rubygems/installer.rb:533:in `rescue in block in build_extensions': ERROR: Failed to build gem native extension. (Gem::Installer::ExtensionBuildError)
    
            /Users/danhixon/.rvm/rubies/ruby-head-patched/bin/ruby extconf.rb 
    extconf.rb:6: Use RbConfig instead of obsolete and deprecated Config.
    checking for ffi.h in /usr/local/include... no
    checking for rb_thread_blocking_region()... yes
    

  59. Adam Palmblad says:

    I adapted the path to apply against ruby 1.9.2-p180, if anyone is interested:

    https://gist.github.com/999435

    Should be basically the same, but with an extern declaration for ruby_find_extname in load.c, and changes to the args of rb_vm_call_cfunc (1.9.2180 seems to expect anohter path arg at the end.)

    It lacks substantial testing.

  60. cies says:

    i also went down from ~17s to ~9s

    tnx, very nice!

    i had to use ffi-1.0.9 and rake-0.8.7 and i get funny deprecation warnings for rbconfig's Config (should be RbConfig).

    apart from that it seems to work well..

    still believe it should be down to 3s;
    pls make a few more of these patches and we're down there in no-time :-P


  61. Collin Miller says:

    @Adam

    Thanks for the 1.9.2 patch :)


    1
    2
    
    wget https://gist.github.com/raw/999435/fc2718ac3f488ab2341b65dc2ae5c123f8859bff/fast-require-ruby-19.2-p180 --no-check-certificate
    rvm install 1.9.2-p180 --patch fast-require-ruby-19.2-p180 -n fastrequire
    

    Bootup time:

    1.9.2-p180
    1
    2
    3
    
    real  0m51.874s
    user  0m43.193s
    sys 0m4.153s
    

    1.9.2-p180-fastrequire
    1
    2
    3
    
    real  0m32.435s
    user  0m24.264s
    sys 0m4.557s
    

  62. Tapajós says:

    Xavier,

    I'm sure that it is a wonderful patch but why your benchmarks uses 1.9.2 and 1.9.3-patched instead of 1.9.3 and 1.9.3-patched?

  63. Justice says:

    Any chance of a patch release of ruby-1.9.2 with this patch included?

  64. Jose A Porras says:

    ruby 1.9.2p180 (2011-02-18 revision 30909) [i686-linux]

    1
    2
    3
    
    real        0m17.823s
    user        0m13.257s
    sys        0m1.108s
    

    ruby 1.9.3dev (2011-06-01 trunk 31867) [i686-linux]
    1
    2
    3
    
    real        0m5.325s
    user        0m4.508s
    sys        0m0.400s
    

    Great Job - Thanks

  65. grobie says:

    1
    2
    3
    4
    5
    6
    7
    8
    9
    
    # ruby 1.9.2p136 (2010-12-25 revision 30365) [x86_64-darwin10.6.0]
    real        0m24.660s
    user        0m21.236s
    sys        0m2.234s
    
    # ruby 1.9.3dev (2011-06-01) [x86_64-darwin10.7.0] with patch
    real        0m21.619s
    user        0m18.043s
    sys        0m1.661s
    

  66. https://www.google.com/accounts/o8/id says:

    Using the 1.9.2-p180 patch I'm getting already initialized constant warnings with a gem that I'm not getting without the patch. Here's the log from pow.

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    
    [Tue, 31 May 2011 17:53:47 GMT] DEBUG nack worker 87410 spawned
    [Tue, 31 May 2011 17:53:51 GMT] WARNING /Users/matthew/.rvm/gems/ruby-1.9.2-p180-fastrequire@fdc/gems/json_pure-1.5.1/lib/json/version.rb:3: warning: already initialized constant VERSION
    [Tue, 31 May 2011 17:53:51 GMT] WARNING /Users/matthew/.rvm/gems/ruby-1.9.2-p180-fastrequire@fdc/gems/json_pure-1.5.1/lib/json/version.rb:4: warning: already initialized constant VERSION_ARRAY
    [Tue, 31 May 2011 17:53:51 GMT] WARNING /Users/matthew/.rvm/gems/ruby-1.9.2-p180-fastrequire@fdc/gems/json_pure-1.5.1/lib/json/version.rb:5: warning: already initialized constant VERSION_MAJOR
    [Tue, 31 May 2011 17:53:51 GMT] WARNING /Users/matthew/.rvm/gems/ruby-1.9.2-p180-fastrequire@fdc/gems/json_pure-1.5.1/lib/json/version.rb:6: warning: already initialized constant VERSION_MINOR
    [Tue, 31 May 2011 17:53:51 GMT] WARNING /Users/matthew/.rvm/gems/ruby-1.9.2-p180-fastrequire@fdc/gems/json_pure-1.5.1/lib/json/version.rb:7: warning: already initialized constant VERSION_BUILD
    [Tue, 31 May 2011 17:53:51 GMT] WARNING /Users/matthew/.rvm/gems/ruby-1.9.2-p180-fastrequire@fdc/gems/json_pure-1.5.1/lib/json/common.rb:98: warning: already initialized constant NaN
    [Tue, 31 May 2011 17:53:51 GMT] WARNING /Users/matthew/.rvm/gems/ruby-1.9.2-p180-fastrequire@fdc/gems/json_pure-1.5.1/lib/json/common.rb:100: warning: already initialized constant Infinity
    [Tue, 31 May 2011 17:53:51 GMT] WARNING /Users/matthew/.rvm/gems/ruby-1.9.2-p180-fastrequire@fdc/gems/json_pure-1.5.1/lib/json/common.rb:102: warning: already initialized constant MinusInfinity
    [Tue, 31 May 2011 17:53:51 GMT] WARNING /Users/matthew/.rvm/gems/ruby-1.9.2-p180-fastrequire@fdc/gems/json_pure-1.5.1/lib/json/common.rb:121: warning: already initialized constant UnparserError
    

  67. Martin Streicher says:

    I get this on iMac.


    check libraries....
    Use ActiveTcl libraries (if available).
    Search tclConfig.sh and tkConfig.sh.....................................
    Valid [tclConfig.sh, tkConfig.sh] are found in [["/System/Library/Frameworks/Tcl.framework", "/System/Library/Frameworks/Tk.framework"], ["/usr/lib", "/usr/lib"], ["/opt/local/lib", "/opt/local/lib"], ["/System/Library/Frameworks/Tcl.framework/Versions/Current", "/System/Library/Frameworks/Tk.framework/Versions/Current"], ["/System/Library/Frameworks/Tcl.framework/Versions/8.5", "/System/Library/Frameworks/Tk.framework/Versions/8.5"], ["/System/Library/Frameworks/Tcl.framework/Versions/8.4", "/System/Library/Frameworks/Tk.framework/Versions/8.4"]]
    Use [tclConfig.sh, tkConfig.sh] == ["/System/Library/Frameworks/Tcl.framework/tclConfig.sh", "/System/Library/Frameworks/Tk.framework/tkConfig.sh"]
    Use MacOS X Frameworks.

    Find Tcl/Tk libraries. Make tcltklib.so which is required by Ruby/Tk.
    configuring tk/tkutil
    configuring win32ole
    configuring zlib
    /bin/sh: line 0: cd: ext/-test-/add_suffix: No such file or directory
    make[1]: *** [ext/-test-/add_suffix/all] Error 1
    make: *** [build-ext] Error 2

  68. kpolitowicz says:

    @Adam: gee, thanks bigtime! Works, all specs pass. And since I'm tired of startup times and - just in case - CI server is there, I'm gonna use this in my dev environment from now on.

    Hope it gets to the next 1.9.2 patch lvl.

  69. Alastair Brunton says:

    Excellent post, I covered my performance benchmarks a wee while ago but wasnt skilled enough to come up with a patch!

    Thanks.

    http://scoop.simplyexcited.co.uk/2011/03/14/rails-3-benchmarks-startup-time/

  70. gustin says:


    awesome xavier!

    --

    rails 3.0.7

    ruby 1.9.2-p180

    24.93 real 18.09 user 2.48 sys


    ruby 1.9.2-p180fastrequire

    15.39 real 9.06 user 2.60 sys

  71. Paul says:

    I took a brief look at 1.8.7 ... is seems it has the same problem. Is that correct?

  72. Paul says:

    Oh sorry ... read past the graphs too quickly :).

  73. PotHix says:

    Æ!!

    I've an error here:


    Copying from repo to src path...
    Applying patch 'tmp/require-performance-fix.patch' (located at /tmp/require-performance-fix.patch)
    ERROR: Error running 'patch -F25 -p1 -f <"/tmp/require-performance-fix.patch"', please read /home/pothix/.rvm/log/ruby-head-patched/patch.apply.require-performance-fix.patch.log
    Running autoreconf
    ruby-head-patched - #configuring

    =/

  74. Sam says:

    @PotHix me too...same error. Anyone?

  75. dgilperez says:

    PotHix, I solved that with a "rvm cleanup".

    After two days of goodness, I'm suffering from this http://pastie.org/2010099

  76. brian says:

    I'm getting the same error as Sam and Pothix. I'm thinking it may be that there may be changes in the ruby trunk which make it so the patch can't be applied cleanly?

  77. roger says:

    does faster_require help?

  78. http://claus.klingberg.myopenid.com/ says:

    Rails-server runs fine, but Rails-Console gives me the same errors / warnings as @dgilperez sees ("already initialized", ....)

  79. taf2 says:

    Based on the core teams patch and back ported to 1.9.2-p180 much simpler patch, not as fast but still much better and way simpler... https://gist.github.com/1008945

  80. Mathias says:

    ruby 1.9.2p188 (2011-03-28 revision 31204) [x86_64-darwin10.6.0]


    real 0m1.378s
    user 0m1.113s
    sys 0m0.263s


    ruby 1.8.7 (2011-02-18 patchlevel 334) [i686-darwin10.6.0], MBARI 0x6770, Ruby Enterprise Edition 2011.03

    real 0m0.651s
    user 0m0.501s
    sys 0m0.144s


    ruby 1.9.3dev (2011-06-07 trunk 31949) [x86_64-darwin10.7.0]


    real 0m0.872s
    user 0m0.770s
    sys 0m0.099s

  81. datnt says:

    Hi,

    I got the same error with: dude posted at May 28, 2011 at 6:24 PM

  82. John Hinnegan says:

    The Autoreconf patch mentioned above has not solved the issue.

    Same error -- cannot install ruby 1.9.2 via rvm.

    is there a way to get an older version of rvm?

  83. John Hinnegan says:

    hours later :

    sudo rvm cleanup all

    seems to have fixed it (and nothing was install via sudo, so it's weird I needed it)

  84. jfelchner says:

    @PotHix @Xavier

    It seems that Github is redirecting the link you have in the instructions in the blog post.

    Add the -L option to curl to get it to follow the redirect.

    Hope this helps!

  85. madsheep says:

    Was your fix included in p290?

  86. michael says:

    I've been using a 1.9.2-p180 with your patch and been happy with the results.
    I was looking forward to seeing a similar speed-up in the just released 1.9.3-preview1, but alas it just isn't there. In fact, the preview of 1.9.3 behaves almost identically to an unpatched 1.9.2. Which means roughly around 15 seconds start up for my rails app, compared to around 10 when using 1.9.2-p180 with the patch. I know there's a couple alternate patches floating around (haven't tried them myself) but seriously, someone upstream needs to pick one that works and get it into the official release. In the meantime, I guess I'm still using that manually patched 1.9.2.

  87. Xavier Shay says:

    @madsheep, no not in p290.

    @michael I'm surprised you didn't see a difference in 1.9.3-preview1. There is a different patch in there which should speed things up. If you have a moment please do report your timings to the ruby-core mailing list, they will really appreciate it.

  88. til says:

    Is there a version of this patch that applies to ruby-1.9.2-p290?

  89. Troy says:

    There is another blog posting on this relating to a patch from the Ruby core team as it relates to faster loading, and a subsequent patch that can be applied to 1.9.2-p290:
    Here's the blog posting: http://www.rubyinside.com/ruby-1-9-3-faster-loading-times-require-4927.html
    And the patch: https://gist.github.com/1008945

    Thank you Xavier for providing a solution which seems to have exerted just enough pressure to get something (even if a different approach) done. My load time was cut by 52.3% using that patch. Also, I used the patch in the link with the instructions in this blog post to make it all work - thanks!

    Before Patch:
    real 0m30.863s
    user 0m25.194s
    sys 0m2.128s

    After Patch:
    real 0m14.191s
    user 0m12.070s
    sys 0m1.911s

  90. Jérémy says:

    [1.9.2-p290]
    real 0m19.499s
    user 0m17.941s
    sys 0m1.300s

    [1.9.2-p290-patched]
    real 0m10.819s
    user 0m9.113s
    sys 0m1.328s

    Thanks a lot Xavier !

  91. Valent says:

    How about 1.9.3 stable? They solved it?

  92. Aragvat says:

    Valent, i think yes.
    Same Rails app loads 2 times faster for me in 1.9.3-p0 comparing to 1.9.2-p290

  93. yuvilio says:

    For those having trouble or not seeing performance pick up, one alternative to patching ruby is to run the rrails server which keeps the loaded rails environment so its not loaded more than once. I wrote an answer on SO explaining it http://stackoverflow.com/a/11479744/462002 .

  94. Chanel Handbags says:

    http://www.coachoutletstoreinuk.com/ Coach Outlet Online
    http://www.coachfactoryoutletanus.com/ Coach Outlet
    http://www.coachoutletonlineunsius.com/ Coach Factory Outlet
    http://www.coachoutletonlinetur.com/ Coach Outlet Online
    http://www.coachfactoryoutletnbsa.com/ Coach Factory Outlet
    http://www.coachfactoryoutletuisa.com/ Coach Outlet Store Online
    http://www.coachoutletstorenie.com/ Coach Outlet Store Online
    http://www.coachfactorystoreuin.com/ Coach Factory Outlet
    http://www.coachfactoryoutletreba.com/ Coach Outlet 
    http://www.coachfactoryoutletonlinesius.com/ Coach Handbags Outlet
    http://www.coachoutletonlinetnse.com/ Coach Outlet
    http://www.coachoutletnoia.com/ Coach Outlet
    http://www.chaneloutletinaus.com/ Chanel Outlet Online
    http://www.louisvuittonoutletina.com/ Louis Vuitton
    http://www.louisvuittonoutletine.com/ Louis Vuitton Outlet
    http://www.guccibeltsoutletbcus.com/ Gucci Belts
    http://www.guccibelststco.com/ Gucci Belt
    http://www.coachoutletstoreinuk.com/ Coach Outlet Online
    http://www.coachfactoryoutletanus.com/ Coach Outlet
    http://www.coachoutletonlineunsius.com/ Coach Factory Outlet
    http://www.coachoutletonlinetur.com/ Coach Outlet Online
    http://www.coachfactoryoutletnbsa.com/ Coach Outlet Store
    http://www.coachfactoryoutletuisa.com/ Coach Outlet Store Online
    http://www.coachoutletstorenie.com/ Coach Outlet
    http://www.coachfactorystoreuin.com/ Coach Factory Online
    http://www.coachfactoryoutletreba.com/ Coach Factory Outlet
    http://www.coachfactoryoutletonlinesius.com/ Coach Factory Outlet
    http://www.coachoutletonlinetnse.com/ Coach Outlet
    http://www.coachoutletnoia.com/ Coach Outlet Store Online
    http://www.chaneloutletinaus.com/ Chanel Outlet Online
    http://www.louisvuittonoutletina.com/ Louis Vuitton Outlet
    http://www.louisvuittonoutletine.com/ Louis Vuitton Handbags
    http://www.guccibeltsoutletbcus.com/ Gucci Belt
    http://www.guccibelststco.com/ Gucci Belts
    http://www.louisvuittonoutletsnib.com/ Louis Vuitton Outlet Online
    http://www.oakleysunglassescnc.name/ Oakley Sunglasses Outlet
    http://www.louisvuittonoutletmoba.com/ Louis Vuitton Outlet Online
    http://www.oakleyssunglassesmobo.com/ Oakley Sunglasses Outlet
    http://www.oakleysunglassesmaba.com/ Cheap Oakley Sunglasses
    http://www.oakleysunglassinsc.com/ Oakley Sunglasses
    http://www.louisvuittonoutletsnib.com/ Louis Vuitton Outlet
    http://www.oakleysunglassescnc.name/ Oakley Sunglasses Outlet
    http://www.louisvuittonoutletmoba.com/ Louis Vuitton Outlet
    http://www.oakleyssunglassesmobo.com/ Oakley Sunglasses Outlet
    http://www.oakleysunglassesmaba.com/ Oakley Sunglasses
    http://www.oakleysunglassinsc.com/ Oakley Sunglasses

Post a comment


(lesstile enabled - surround code blocks with ---)

A pretty flower Another pretty flower