Search code examples
ruby-on-railsperformancerakejruby

Slow basic operations JRuby rake task


I'm trying to diagnose a performance problem with JRuby and Rails without much luck.

Essentially, I have a JRuby on Rails 5 application that is going to kick off processes in rake tasks. When testing some of the rake tasks, we noticed a significant slowdown compared to our old scripts we used that were written in MRI ruby and ran using a bundle exec ruby <script> call.

Basic operations on strings, arrays, numbers, etc in the context of a rake task are 5-6x slower. For example, take this simple test:

bin/rake performance_test:start

where performance_test.rake is:

namespace :performance_test do
  desc 'Test Performance'
  task :start do
    Benchmark.bmbm do |x|
      x.report ('double') do
        100_000_000.times do
          "Hello world!"
        end
      end
    end
  end
end

produces these results:

Rehearsal ------------------------------------------
double  27.570000   0.630000  28.200000 ( 27.714908)
-------------------------------- total: 28.200000sec

             user     system      total        real
double  28.050000   0.750000  28.800000 ( 29.864897)

while running this:

jruby -G performance_test.rb

where performance_test.rb is:

require 'require_all'
require 'bundler'
Bundler.require(:default)
require_all Dir.glob('lib/extensions/*.rb')

Benchmark.bmbm do |x|
  x.report ('double') do
    100_000_000.times do
      "Hello world!"
    end
  end
end

gives me these results:

Rehearsal ------------------------------------------
double   4.930000   0.240000   5.170000 (  5.639570)
--------------------------------- total: 5.170000sec

             user     system      total        real
double   4.420000   0.180000   4.600000 (  5.538717)

I've tried almost every JVM and JRuby option that is available and searched for information on this without any luck. Would be great if I could get to the root cause of this and how I would go about fixing the issue.


Solution

  • You would probably get our attention better if you filed it as a JRuby bug, even though it's not really a bug :-)

    I believe your numbers are probably under JRuby 1.7, or an early version of JRuby 9k that did not JIT compile blocks independently. Here's my results under JRuby 9k master (9.1.8.0):

    ~/projects/jruby/tmp $ jruby performance_test.rb 
    Rehearsal ------------------------------------------
    double   3.180000   0.130000   3.310000 (  2.801371)
    --------------------------------- total: 3.310000sec
    
                 user     system      total        real
    double   2.740000   0.030000   2.770000 (  2.700693)
    
    ~/projects/jruby/tmp $ rake performance_test:start
    Rehearsal ------------------------------------------
    double   3.890000   0.110000   4.000000 (  3.499264)
    --------------------------------- total: 4.000000sec
    
                 user     system      total        real
    double   3.430000   0.040000   3.470000 (  3.382129)
    

    The Rake numbers are bit slower, but not 5x slower as in your example.

    If you're running with JRuby 1.7.x, you could try to pass -X+C to JRuby (JRUBY_OPTS=-X+C) to force all files to compile, but there's some that might not succeed to compile.