JRuby 1.1 RC2 Real World Performance

With the recent release of JRuby 1.1 RC2 I’ve rerun my ‘Real World Performance’ benchmarks. In addition to my normal run I’ve added a second longer run, and the results surprised me. Let me tell you what I did, and then we can take a look at the results.

In both cases I use an application that builds a catalog of good and bad patterns. Then it reads in syslog output and compares the log entries against the catalogs, sending different kinds of notifications depending on the configuration. While this sounds like it might be IO bound, profiling shows that much of the time is actually spent in Array operations and comparisons.

The original, shorter benchmark does ten iterations. Each iteration starts JRuby, creates the catalogs, then processes 73607 log entries.

The new, longer benchmark does three iterations (I didn’t want to take too much time). Each iteration starts JRuby, creates the catalogs, and processes 407749 log entries.

With that out of the way, here are the original style results:

Version	Average Run Time	stdev	time/syslog entry
JRuby 1.0.3	21.63	0.21	0.00029
JRuby 1.1 RC1	15.79	0.27	0.00021
JRuby 1.1 RC2	15.74	0.24	0.00021

For JRuby 1.0.3, I set the JAVA_OPTS like this:

JAVA_OPTS="-Djruby.objectspace.enabled=false \
  -Djruby.jit.enabled=true -server"

and ran each iteration like this:

jruby -C logwatcher.rb < 20_minute_log

JRuby 1.1 had the following JAVA_OPTS:

JAVA_OPTS="-Djruby.objectspace.enabled=false \
  -Djruby.compile.mode=JIT -server"

RC1 was executed like this:

jruby -C logwatcher.rb < 20_minute_log

and RC2 like this:

jruby -X-C logwatcher.rb < 20_minute_log

(Between RC1 and RC2, the JRuby team added the -X prefix to the compilation switch to prevent a conflict with MRI’s -C switch.) The -C switch turns off compilation, which is faster on these shorter runs. I also tried using the +C, but am ignoring the results for now.

The results of the new style benchmark looks like this:

Version	switches	Average Run Time	stdev	time/syslog entry
JRuby 1.0.3	-C	127.90	15.8	0.00174
JRuby 1.1 RC1	-C	231.86	30.2	0.00315
JRuby 1.1 RC2	-X-C	218.93	34.89	0.00297
JRuby 1.1 RC2	-X+C	193.15	8.56	0.00262

The first thing that jumps out at me is that the 1.1 release candidates are significantly worse that the 1.0.3 release. The other thing is that performance (measured per entry) degraded on the longer run. The former is something that the JRuby team might want to look at, while the latter means I probably need to look at my code.

I used the same JAVA_OPTS settings shown in the original style tests, but I did run the RC2 version with compilation turned on (and did see an improvement). I should probably set aside a couple of hours to let these tests run against an even larger data set at some point.

Please, don’t assume that your app will end up with the same performance characteristics that LogWatchR has. Run your own performance measurements … and think about posting them, it will help all the implementations get better.