.

Coffee Powered

code and content
Jun
17
2011

JRuby Performance: Exceptions are not flow control

I started playing with JRuby tonight, and got my application up and running on it in under 10 minutes (kudos to the JRuby team!), but when I started measuring its performance, I was seriously unimpressed. This didn’t quite line up with what I’ve read of JRuby, so I decided to do a little digging.

Exception to the rule

I hopped into #jruby and was fortunate enough to get to talk to headius directly. He pointed me towards problems with older versions of the i18n gem, which got me thinking – perhaps there were other abuses of exceptions as flow control in my app. After using jconsole to measure my exceptions-per-request, I found that I was generating several hundred exceptions per request, which was imposing a significant slowdown on my requests. After a quick discussion, headius committed a change to add logging switches for exceptions. I was able to fire up my trinidad instance with logging switches:

jruby -Xlog.exceptions=true -Xlog.backtraces=true -Xlog.callers=true -S trinidad 2>&1 | grep "Backtrace generated" -A4

and I instantly had data at my disposal. The ugly areas became clear very quickly – CarrierWave, MongoMapper, and surprisingly, Haml were my top offenders.

Haml:          117 exceptions
CarrierWave:   162 exceptions
MongoMapper:   114 exceptions

The stack traces themselves are easy to interpret, too:

Backtrace generated:
NameError: undefined local variable or method `_hamlout' for #<ActionView::Base:0x1af81d1c>
               eval at org/jruby/RubyKernel.java:1088
     block_is_haml? at /usr/local/rvm/gems/jruby-head/gems/haml-3.1.2/lib/haml/helpers.rb:543
  capture_with_haml at /usr/local/rvm/gems/jruby-head/gems/haml-3.1.2/lib/haml/helpers/action_view_mods.rb:90
1

This gave me an easy target:

1

What's happening here is the block is evaluated with just <code>_hamlout</code>, which throws a NameError if the variable doesn't exist in the block's binding context, and then the proper boolean is returned. However, this is a perfect example of exceptions as flow control - the question is "Does _hamlout exist in the block context?", and that's not best answered by a NameError. Ruby gives us <code>defined?</code> to check that sort of thing trivially, and more importantly, idiomatically. So, I can just rewrite that helper as:

1

This is both far more correct, and far faster.

<h2>Lies, Damn Lies, and Benchmarks</h2>

Let's try a quick benchmark to test the effects of each method:

1

And results:

1
[chris@luna repos]$ rvm use ree
Using /usr/local/rvm/gems/ree-1.8.7
[chris@luna repos]$ ruby test.rb
Rehearsal --------------------------------------------
Rescue     0.070000   0.010000   0.080000 (  0.082649)
defined?   0.020000   0.000000   0.020000 (  0.022991)
----------------------------------- total: 0.100000sec

               user     system      total        real
Rescue     0.080000   0.000000   0.080000 (  0.082292)
defined?   0.030000   0.000000   0.030000 (  0.022384)

Avoiding extraneous exceptions is clearly better on MRI (3.6x faster using defined? rather than NameError), but 100k exception raises only imposes an extra 0.6 seconds of runtime on the test. Probably not worth fretting over to too great a degree, at least until other optimizations have been made.

Let’s try JRuby:

[chris@luna repos]$ rvm use jruby-head
Using /usr/local/rvm/gems/jruby-head
[chris@luna repos]$ jruby --server --fast test.rb
Rehearsal --------------------------------------------
Rescue    11.145000   0.000000  11.145000 ( 11.097000)
defined?   0.599000   0.000000   0.599000 (  0.599000)
---------------------------------- total: 11.744000sec

               user     system      total        real
Rescue     9.758000   0.000000   9.758000 (  9.758000)
defined?   0.357000   0.000000   0.357000 (  0.357000)

Holy crap, now we’re in interesting territory. Using defined? rather than letting exception handling do our dirty work for us is 27.3x faster. As Headius explains:

In JRuby 1.6, we moved to using JVM-level facilities for generating exception backtraces. These facilities are considerably more expensive than the artificial backtraces we had been maintaining before…not incredibly expensive, but not free or as cheap as they used to be by any means. If applications and libraries use exceptions for exceptional error cases, it’s not a big deal.

The message here is pretty clear – use exceptions for things that are exceptional, not for flow control of the normal program operation. It’s worth noting that in the benchmark, there isn’t a big stack trace to generate; in a Rails app, each exception is going to generate a stack trace scores of entries deep, further exacerbating the problem. This is a simple test, and a simple case, but it illustrates the point fairly clearly.

By using the new exception logging switch, I was able to, in about an hour, monkeypatch several of the libraries we were using to reduce my exceptions-per-request from 400 to 8. This had an extremely noticable impact on my page times, reducing my test action runtimes significantly. If you’d like to take a look at all the pieces I patched, check this quick pastie. I’m working on patches to submit to each of these projects; besides avoiding punching JRuby in the tenders, it also improves runtimes in MRI and REE Ruby VMs.

In all three libraries, exceptions were being used as flow control to answer “does this variable or method exist?”, and in all three cases, the libraries are doing it wrong; Ruby gives us defined? and respond_to?, and if you mean “Is this variable defined?”, why not ask “defined? variable” rather than “try to use this and hit the eject button if it doesn’t work”?

Exceptions are for things like “The remote service returned a bad response”, or “That string didn’t parse as valid JSON”, or “That file which you’re trying to parse as an image isn’t actually an image” – exceptional circumstances. Things that you don’t expect. If you’re using exceptions to answer a question, or as a poor-man’s GOTO, you may want to reevaluate how you’re using them.

JRuby as an exceptions-as-flow-control detector

It’s worth noting as a quick side item here that the commit to JRuby tonight makes JRuby a fantastic tool for locating libraries that use the exceptions-as-flow-control antipattern in your Rails apps. I tried a number of approaches to monkeypatching Exception before Headius committed the change, none of which worked very well, but once I built jruby-head, I had every exeception trace in my application laid out before me. You might consider taking a crack at this on your own apps – you might like what you find.

Getting running is as easy as:

rvm install jruby-head --branch jruby-1_6
rvm use jruby-head
gem install bundler trinidad
bundle install
jruby -Xlog.exceptions=true -Xlog.backtraces=true -Xlog.callers=true -S trinidad 2>&1 | grep "Backtrace generated" -A4

In a matter if minutes, you’ll have an abundance of stack traces to chew on at your leisure. Or, if you’re lucky, you won’t have much of anything at all. Good hunting!

To sum up:

This is flow control:

This is exception handling:

Make sure you’re pressing the right button.

  • http://qmx.me Douglas Campos (qmx)

    amazing post :)

  • Charles Nutter

    A tip for folks reading this (which I should have posted yesterday)…

    Kernel#rails has a form that allows you to pass in a backtrace for the exception, like this:

    raise SomeException, ‘some message’, []

    Since the really costly part of generating an exception is generating a backtrace for it, this blunts that cost completely. It’s still more expensive in most cases than proper flow control, since you’re still creating an Exception object and unrolling stack…but if there’s no other way, it’s a nice trick.

    In addition, many uses of exceptions as flow control can be replaced by Ruby’s catch/throw. catch/throw allows you to jump out of a deep stack fairly quickly, which can be useful for recursive algorithms where you don’t want specialized return values or return sleds (objects that carry both value and status).

    So, for example, you can do this:

    catch :reset do
    call_some_deep_algorithm
    end

    …

    def call_some_deep_algorithm
    if failure_deep_in_stack
    throw :reset
    else
    …
    end
    end

    The effect here is to unroll the entire stack with considerably less cost than the typical exception.

    Thanks for the excellent post!

  • Anonymous

    Well done. Only nit is that you can use defined? without eval.

    >> !!defined?(_hamlout)
    => false

  • http://twitter.com/calavera David Calavera

    Never two pictures where so self explanatory

  • http://coffeepowered.net Chris Heald

    You can, certainly, but the example given is a Haml patch, which is checking the block binding for the existence of _hamlout, for which you do need eval.

  • Anonymous

    But without passing the binding to the eval you’re just using the current binding, right? e.g.,

    eval(“foo”)

    vs.

    eval(“foo”, somebinding)

  • http://nosql.mypopescu.com Alex Popescu

    It would be worth noting that some languages to encourage the EAFP programming style (easier to ask forgiveness than permission). Not sure it’s Ruby’s case, but as far as I remember Python duck typing definition mentions EAFP.

  • http://twitter.com/andrewjgrimm Andrew Grimm

    While saying “exceptions as flow control is bad, mmmkay?” is a good point to make, it may be worth checking out why people do it.

    For example, people may be using EAFP if they think respond_to? hasn’t been implemented properly when method_missing has been modified. Or they think defined? is computationally expensive.

    I’m guilty of require “some_library” rescue LoadError – maybe I should see what the alternatives are…

  • http://coffeepowered.net Chris Heald

    There are certainly cases where exceptions are the right thing to use, and I really don’t have any issue with that – for example, if method_missing has been modified and respond_to? won’t return what you expect from some third-party library, then yeah, you have to work around it. However, I firmly believe you should be as intentional as possible with your code, and in most – not all – cases, using begin…rescue instead of if..else is poor design.

    I would personally make an exception for require -> rescue, because Ruby’s loading pipeline is pretty complex, and likely isn’t worth all the work to make it happen more idiomatically. (This assumes the lack of some sort of “is there something with this name in the load path” method, which I’m fairly certain there isn’t). Additionally, that’s the sort of thing that’ll only happen once per program run. In the context of this post, I’m primarily bagging on the lazy usage of “rescue nil” instead of type checking or introspection, both of which ruby makes easy.

    What I’m really arguing for here is using the best tool for the job, and making the case that exceptions are often abused as a general-purpose multitool rather than a very specific tool. When exceptions are the right tool for the job, or if they are the least-wrong tool for the job, then use them, by all means, but don’t use a hammer as a screwdriver just because you already have a hammer in hand.

  • http://coffeepowered.net Chris Heald

    In Python’s case, this is true; Python does make heavy use of exceptions for control flow, its exceptions are very fast, and if that’s considered idiomatic, then…well, okay, go for it. My beef isn’t with the concept of exceptions in general as much as it is with using a hamfisted one-size-fits-all solution to a more specific puzzle.

    In all the cases I evaluated in my app, exceptions were being raised and then caught as ‘rescue nil’ (which will catch -any- exception) in order to handle one specific condition. In addition to being less self-documenting, this pattern also has the potential to obscure other bugs. In the case of JVM-based languages, it’s also exceptionally slow, as backtrace generation is not trivial.

  • http://twitter.com/andrewjgrimm Andrew Grimm

    Minor nitpick: rescue nil will only catch StandardErrors, not literally *any* Exception. If velociraptors are attacking, you’ll still find out.

  • http://www.codewithstyle.eu Fabio

    Great article, well done…

  • http://freemusicformormons.com/lds-ward-choir-music roger pack

    has this been improved since?

  • http://trusteesalesol.shikshik.org/2012/09/04/jruby-performance/ Jruby performance | Trusteesalesol

    [...] Coffee Powered » JRuby Performance: Exceptions are not flow controlJun 17, 2011 … I started playing with JRuby tonight, and got my application up and running on it in under 10 minutes (kudos to the JRuby team!), but when I … [...]