Making Sense out of Slow Rubygems Startup
JRuby is pretty fast these days, in most cases it is faster than MRI. JRuby is especially good at handling long-lasting repeating tasks (on server side). But one thing where JRuby is not blazingly fast is during the startup. Well, actually, JRuby starts up within 0.5 second, which is really nice for the JVM-based implementation. But as soon as rubygems comes into play, the situation gets worse.
So, I spent some time trying to understand why just loading the rubygems package eats up a second or two more. Well, it turned out that rubygems loads almost entire standard library, which is crazy! Sure, this is a bit of exaggeration, but still, let’s see, shall we?
First, fileutils are loaded, 100+ms passed, then rubygems tries to figure out where is the system-level config file, and for that on Windows it uses Win32API library (!!!), which in turn requires FFI (the native interface). Ka-ching, 300+ ms for that. Then, we need to read the configs and stuff, this requires YAML parser, and in JRuby that means loading Yecht, 350+ ms more. Next, JRuby provides some extension of rubygems functionality, like possibility to load gems from the JAR files, and for that we need some classpath magic and the ‘uri’ library. To obtain the JRuby’s classloader, we need to require ‘jruby’, which in turn requires ‘java’, and the java library loads the whole bunch of extra functionality (which we are not using here, btw), that adds up to 400 ms. So, we barely loaded the rubygems library, but already consumed 1200ms of time, or more.
Take a look at the following picture that shows the times to load all those libraries:
As you see, loading rubygems themselves is not that time consuming, most of the time is spent in loading the dependencies. There are some low-hanging fruits here, like lazily loading the ‘uri’ library. I also don’t like that rubygems loads the Win32API and the whole FFI stuff, removing that would also eliminate quite a lot of startup time. Loading the whole bunch of java integration magic in order to only be able to obtain the JRuby classpath also seems to be overkill. All those tweaks, if implemented, might actually cut the rubygems startup time in half. We’ll see.
UPDATE: Wayne Meissner has just tweaked the loading of Win32API, and I adjusted JRuby-specific rubygems tweaks to lazily load the ‘uri’. So, the loading of rubygems is already about 200ms faster than it was yesterday!
UPDATE#2: Here’s the log of rubygems loading timings in JRuby, in easy to read text format: http://gist.github.com/240322.
December 11th, 2009 at 7:36 pm
Thanks for the write-up, very informative! I’ve been running into slow RubyGems startup in MRI land and this writeup shed some light on a few of the issues.