JRuby 1.5.0RC1 - Startup Times

Ruby JRuby
1

Hi,

Startup times are important for the command line toolkit that I have
been writing in JRuby.

I did some very quick tests once the JRuby 1.5.0RC1 release was made,
with regards to startup times, e.g.

jruby -b -v -e "require 'rubygems'"

The results comparing execution times on a Windows OS, running Java
1.6.0_19 32bit, client mode, between 1.4 and 1.5RC1 showed a good
improvement.

JRuby 1.4 1093ms
JRuby 1.5RC1 812ms

Ignoring the first execution to allow Windows to cache/load any JVM
DLLs.

Based on the above I started to think that I should see some good
improvements with my own command line tools. However, this was not the
case:

JRuby 1.4 1390ms
JRuby 1.5RC1 1438ms

It was a little disappointing not to see a similar drop.

Requesting a loadService timing, I can see that the RubyGems require
step takes pretty much the same amount of time as in the previous tests,
with the biggest additional chunks of time, being for requiring, dbi,
erubis and java.

Performing some independent tests for each of these, it looks as if in
general the times are better in 1.5RC1, which got me wondering what the
cause of the slow down was, and as it turns out, it is still in the
require, but seems to be due to a compound effect of requiring multiple
gems. For example:

jruby -b -v -e "require 'rubygems'; require 'dbi'"

JRuby 1.4 1235ms
JRuby 1.5RC1 1000ms

As can be seen, the difference has reduced slightly, now lets add
another library:

jruby -b -v -e "require 'rubygems'; require 'dbi'; require 'java'"

JRuby 1.4 1234ms
JRuby 1.5RC1 1125ms

As can be seen the 1.4 times have not really changed when java is added,
but the 1.5RC1 times have.

Then adding the next gem, we get:

jruby -b -v -e "require 'rubygems'; require 'dbi'; require 'erubis';

require ‘java’"

JRuby 1.4 1266ms
JRuby 1.5RC1 1203ms

The gap shrinks further.

Just something else interesting, was the position of the requires, if
java was first, then the times seem to come through slower.

I am hoping that the cause of this is something simple, and that with
further tests that it can be identified and rectified, as this would
dramatically improve the startup times if we can keep the initial
improvement.

Great work guys with the 1.5RC1 release, other than the above, I have
not found any issues. In general once the startup has been overcome, the
performance does seem better.

Thanks

Regards
Matthew W.

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email
2

Hi Matthew,

Yeah, we optimized some of the basic startup scenarios (like startup
of rubygems) a bit, not loading stuff at startup if we could. But as
soon as you have all the libs in your app startup (including java,
rubygems, etc), then you’ll get about the same level as with JRuby
1.4.

The thing is JRuby’s performance at startup is not perfect (as with
almost any jvm-based language), and parsing/loading all the required
libs while JIT is not really working at its peak perf, is not fast. We
improved things a bit, trying not to load things, but the real and
rather hard problem is to overcome the slowness at loading – that
wasn’t fully addressed yet.

Thanks,
–Vladimir

On Sun, Apr 18, 2010 at 3:56 PM, Matthew W. [email protected]
wrote:

   JRuby 1.4                       1093ms

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email
3

Hi,

So all I am seeing is the unwinding of some form of lazy loading
optimisation performed in 1.5RC1.

Interesting output from the loadService timing suggests that majority of
the time is spent defining Ruby types, whether that be for YAML or for
other libraries. May have to do some profiling to see exactly what the
main cause is, as this could be a big win area for startup optimisation.

I have also pin-pointed a few libraries which I can lazy load in my own
command line tools, so hopefully I should see some benefits once I
complete the refactoring. Maybe save a few hundred milliseconds.

Thanks.

Regards
Matthew W.

On 19/04/2010, at 12:35 AM, Vladimir S. wrote:

libs while JIT is not really working at its peak perf, is not fast. We

Startup times are important for the command line toolkit that I have been writing in JRuby.
Ignoring the first execution to allow Windows to cache/load any JVM DLLs.
Performing some independent tests for each of these, it looks as if in general the times are better in 1.5RC1, which got me wondering what the cause of the slow down was, and as it turns out, it is still in the require, but seems to be due to a compound effect of requiring multiple gems. For example:
JRuby 1.4 1234ms

Regards
To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email