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_logJRuby 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_logand 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.
Jruby 1.0.2 
Jruby 1.0.3 
Jruby 1.1b1 
Jruby 1.1RC1 
