Friday, January 11, 2008

Real World Rubinius Performance

Well, I have good and bad news from the Rubinius front. This morning, I built the latest Rubinius from the git repository, and gave LogWatchR another try … and it worked! This is a huge step forward from my perspective, since I’ve had all kinds of wierd failures in the past.

The bad news (well, bad is an overstatement, let’s say ‘not so good news’) is that the performance is pretty bad at this point. To be fair, the Rubinius team is still focused on completeness. I’d expect performance to improve once they turn their eye to it.

Here’s my 30 second recap:

My ‘real world performance’ timings run a small Ruby app called LogWatchR, which scans syslog data for cataloged good and bad patterns. I feed it about 73,000 syslog entries (about 20 minutes worth) that I’ve got archived. I measure the execution time against repeated runs, and find the average run time and standard deviation.

Rubinius’ first successful run clocked in at an average of 143.03 seconds, with a standard deviation of 0.56 seconds.

Given that things took so long, I thought I’d try a quick profiling run too (I only ran against 1000 log entries though, to save time). Here’s the abbreviated version of what the profiler told me:

../shotgun/rubinius -r profile logwatcher.rb < short_log
Total slices: 160, 2680000 clocks
 % time   slices   name
   8.75       14   String#[]
   8.12       13   Hash#[]
   6.88       11   Array#<<
   6.88       11   Object#kind_of?
   5.00        8   #.single_load
   4.38        7   String#split
   4.38        7   Hash#keys
   4.38        7   Regexp#match_from
   3.75        6   Hash#[]=
   2.50        4   String#substring
   2.50        4   Array#replace

Now for the amazing part, the sampling debugger took almost no extra time, clocking in at 3.009 seconds of real time while a regular run took 2.805 seconds. Wow! I’m looking forward to seeing what the Legion of Rubinius Heroes can do with performance over the next couple of months.

If you’re interested in seeing more performance information, you might want to look at:

I’ve also written about profiling if you’d like to read more about that.

7 comments:

Anonymous said...

So... how does it compare to MRI?

pate said...

@anonymous, if you look at the "Performance Real World Performance on Boxing Day" link above, you can see the whole deal. The short answer is that Ruby 1.8.5 and 1.9.0 both run in about 10.5 seconds so Rubinius is say slower right now.

pate said...

*sigh* way slower, not say slower ...

tmornini@engineyard.com said...

Hey there!

Thanks for the Rubinius coverage!

It's really gratifying to see that Rubinius is going from a concept to a Ruby. :-)

You're absolutely 100% correct that the team is entirely focused on being a complete Ruby, and perhaps as importantly, a complete Ruby spec!

In Evan's own words "There are entire continents of unexplored performance enhancements."

For instance, there are very clear plans, architecturally, to allow for JIT compilation.

Additionally, there really hasn't been any work done on the *ruby* portions of the basic class implementations such as String and Array.

String, for instance, is currently about 55x slower than MRI, but that will pass. :-)

In the last six months, the project has gone from around 1200x slower on portions of the YARV benchmark suite, to about 55x slower at worst. That is the kind of progress we're intending to maintain. :-)

Phil said...

That's funny; Bus Scheme was slightly faster on Rubinius than 1.8 last I checked. It can't catch 1.9 yet though, but that will come with time.

pate said...

@phil

have you got any examples/benchmarks of bus scheme on Rubinius? I'd love to see 'em.

Anonymous said...

as much as i love rubinius, and think it may serve as a role model for future great projects.... it sounds as if there is a HUGE amount of work left :(