I am in the process of switching a major application from MRI Ruby (specifically 1.8.7-p302) using many C extensions to jRuby (currently trying 1.5.3-master). In my application, performance is extremely important. It is so important in fact, that I will be writing about some of my experiences in troubleshooting the speed and getting those important milliseconds back. When I am trying to keep an entire transaction from start to finish under 40ms and just the decoding of a JSON object into a Ruby object in jRuby takes roughly 30ms using json_pure, we may have to explore other avenues.
Just to verify that JSON was indeed as slow as I thought it was, here is a quick benchmark of it:
1 2 3 4 | require 'json/pure' Benchmark.bmbm do |x| x.report("parse:") { JSON.parse(json) } end |
JSON Pure Results:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 | Rehearsal ------------------------------------------ parse: 0.255000 0.000000 0.255000 ( 0.255000) --------------------------------- total: 0.255000sec user system total real parse: 0.024000 0.000000 0.024000 ( 0.024000) parse: 0.017000 0.000000 0.017000 ( 0.017000) parse: 0.032000 0.000000 0.032000 ( 0.032000) parse: 0.042000 0.000000 0.042000 ( 0.041000) Rehearsal ------------------------------------------- encode: 0.036000 0.000000 0.036000 ( 0.035000) ---------------------------------- total: 0.036000sec user system total real encode: 0.010000 0.000000 0.010000 ( 0.010000) encode: 0.007000 0.000000 0.007000 ( 0.006000) encode: 0.006000 0.000000 0.006000 ( 0.006000) encode: 0.017000 0.000000 0.017000 ( 0.016000) |
That wasn’t so great. We’re looking at about 30ms on average to decode and an additional about 10ms to re-encode. If we want to keep our total transactions to 40ms and we haven’t even done anything with our data, we’re in pretty bad shape. Let’s try the same thing again, only this time with json-jruby.
1 2 3 4 | require 'json/pure' Benchmark.bmbm do |x| x.report("parse:") { JSON.parse(json) } end |
JSON-jRuby Results:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 | Rehearsal ------------------------------------------ parse: 0.009000 0.000000 0.009000 ( 0.008000) --------------------------------- total: 0.009000sec user system total real parse: 0.003000 0.000000 0.003000 ( 0.002000) parse: 0.007000 0.000000 0.007000 ( 0.003000) parse: 0.003000 0.000000 0.003000 ( 0.003000) parse: 0.002000 0.000000 0.002000 ( 0.002000) Rehearsal ------------------------------------------- encode: 0.009000 0.000000 0.009000 ( 0.009000) ---------------------------------- total: 0.009000sec user system total real encode: 0.001000 0.000000 0.001000 ( 0.001000) encode: 0.001000 0.000000 0.001000 ( 0.001000) encode: 0.001000 0.000000 0.001000 ( 0.001000) encode: 0.001000 0.000000 0.001000 ( 0.001000) |
Much better, right. We’re averaging 2.5ms to decode it and 1ms to encode it. That’s much more tolerable.
Just for poops and laughs, we should compare this to our MRI version with C bindings (the version we were using before), the super fast yajl-ruby gem.
1 2 3 4 5 6 7 8 9 | require 'yajl' parser = Yajl::Parser.new Benchmark.bm do |x| x.report("parse:") { parser.parse(json) } end parsed = parser.parse(json) Benchmark.bm do |x| x.report("encode:") { parsed.to_json } end |
And here are the MRI Yajl-ruby results:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 | Rehearsal ------------------------------------------ parse: 0.000000 0.000000 0.000000 ( 0.000159) --------------------------------- total: 0.000000sec user system total real parse: 0.000000 0.000000 0.000000 ( 0.000101) parse: 0.000000 0.000000 0.000000 ( 0.000093) parse: 0.000000 0.000000 0.000000 ( 0.000098) parse: 0.000000 0.000000 0.000000 ( 0.000093) user system total real encode: 0.000000 0.000000 0.000000 ( 0.000063) encode: 0.000000 0.000000 0.000000 ( 0.000063) encode: 0.000000 0.000000 0.000000 ( 0.000064) encode: 0.000000 0.000000 0.000000 ( 0.000065) |
These benchmarks are by no means exact, but they do give you a feel for the fact that jRuby is slower than MRI with C extensions. The comparison is essentially 3.5ms round trip in jRuby and about 1.5ms in MRI. It might not seem like a lot, but when every millisecond counts, there is a lot that can happen in those extra 2 milliseconds that could be available every transaction.
Note: I reran the code by hand and formatted the results by hand, so the code won’t exactly produce the results above. These benchmarks were all done on my 2008 MacBook Pro with 4G of RAM and an Intel 2.53GHz Core 2 Duo.
UPDATE: It has been pointed out to me that I didn’t take advantage of jRuby’s hotspot feature (Thanks NickSeiger and Charles Remes). Hotspot basically kicks in after it figures out the best ways to optimize the code. So here are some new results and it’s safe to note that json-jruby is so fast, that the computer can’t time it.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 | jRuby json_pure: Rehearsal ------------------------------------------ parse: 0.001000 0.000000 0.001000 ( 0.001000) --------------------------------- total: 0.001000sec user system total real parse: 0.001000 0.000000 0.001000 ( 0.000000) Rehearsal ------------------------------------------- encode: 0.001000 0.000000 0.001000 ( 0.001000) ---------------------------------- total: 0.001000sec user system total real encode: 0.000000 0.000000 0.000000 ( 0.000000) jRuby json-jruby: Rehearsal ------------------------------------------ parse: 0.000000 0.000000 0.000000 ( 0.000000) --------------------------------- total: 0.000000sec user system total real parse: 0.000000 0.000000 0.000000 ( 0.000000) Rehearsal ------------------------------------------- encode: 0.000000 0.000000 0.000000 ( 0.000000) ---------------------------------- total: 0.000000sec user system total real encode: 0.000000 0.000000 0.000000 ( 0.000000) |
