Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

JRuby 9000 performance with --debug is 4-5x slower than JRuby 1.7.2 or Ruby 2.3.3 #4909

Closed
nightsurge opened this issue Dec 20, 2017 · 7 comments
Closed

JRuby 9000 performance with --debug is 4-5x slower than JRuby 1.7.2 or Ruby 2.3.3 #4909

nightsurge opened this issue Dec 20, 2017 · 7 comments
Labels
performance
Milestone
JRuby 9.1.16.0

Comments

@nightsurge
Copy link

nightsurge commented Dec 20, 2017 •
edited by enebo
Loading

JRuby 9k does not JIT when run in --debug and it runs quite a bit slower than 1.7.x.

Environment

*JRuby 9.1.13.0
*JRuby 1.7.2
*C/MRI Ruby 2.3.3
*MacOS 10.12.6
*JRUBY_OPTS=-J-Xmx2048m -J-Xmn512m --server --debug

Expected Behavior

Similar or better performance in JRuby 9000 as JRuby 1.7.2 / C|MRI Ruby 2.3.3

Actual Behavior

Performance is lower by a factor of 4-5x!

JRuby 9000

 Warming up --------------------------------------
        Instantiation   318.000  i/100ms
           Direct hit   354.000  i/100ms
         Class method   327.000  i/100ms
 Calculating -------------------------------------
        Instantiation      3.541k (± 3.5%) i/s -     35.616k in  10.071956s
           Direct hit      3.605k (± 2.6%) i/s -     36.108k in  10.021532s
         Class method      3.646k (± 3.5%) i/s -     36.624k in  10.058927s

 Comparison:
         Class method:     3646.1 i/s
           Direct hit:     3605.5 i/s - same-ish: difference falls within error
        Instantiation:     3540.7 i/s - same-ish: difference falls within error

JRuby 1.7.2

Warming up --------------------------------------
       Instantiation     1.119k i/100ms
          Direct hit     1.252k i/100ms
        Class method     1.335k i/100ms
Calculating -------------------------------------
       Instantiation     13.655k (± 4.8%) i/s -    136.518k
          Direct hit     13.610k (± 4.8%) i/s -    136.468k
        Class method     13.789k (± 4.1%) i/s -    138.840k

Comparison:
        Class method:    13789.3 i/s
       Instantiation:    13654.6 i/s - same-ish: difference falls within error
          Direct hit:    13610.2 i/s - same-ish: difference falls within error

Ruby 2.3.3

Warming up --------------------------------------
       Instantiation     1.542k i/100ms
          Direct hit     1.524k i/100ms
        Class method     1.536k i/100ms
Calculating -------------------------------------
       Instantiation     15.530k (± 4.7%) i/s -    155.742k in  10.051104s
          Direct hit     15.359k (± 5.4%) i/s -    153.924k in  10.051651s
        Class method     15.744k (± 3.8%) i/s -    158.208k in  10.064287s

Comparison:
        Class method:    15744.0 i/s
       Instantiation:    15530.4 i/s - same-ish: difference falls within error
          Direct hit:    15359.1 i/s - same-ish: difference falls within error

Very simple/generic test… JRuby 9000 is 4-5 times slower than JRuby 1.7.2/Ruby 2.3.3

Benchmark

require 'benchmark/ips'

class MyClass
  def self.call
    new.foo
  end

  def self.foo
    a = []
    1_000.times do |i|
      a << i
    end
    a
  end

  def foo
    a = []
    1_000.times do |i|
      a << i
    end
    a
  end
end

Benchmark.ips do |x|
  x.time = 10
  x.warmup = 3
  x.report("Instantiation") { MyClass.call }
  x.report("Direct hit") { MyClass.new.foo }
  x.report("Class method") { MyClass.foo }

  x.compare!
end
@headius
Copy link
Member

headius commented Dec 20, 2017

I cannot reproduce this:

$ jruby -v blah.rb
jruby 9.1.13.0 (2.3.3) 2017-09-06 8e1c115 Java HotSpot(TM) 64-Bit Server VM 25.131-b11 on 1.8.0_131-b11 +jit [darwin-x86_64]
Warming up --------------------------------------
       Instantiation     2.200k i/100ms
          Direct hit     2.387k i/100ms
        Class method     2.199k i/100ms
Calculating -------------------------------------
       Instantiation     25.129k (± 4.1%) i/s -    250.800k in   9.998143s
          Direct hit     26.981k (± 5.3%) i/s -    269.731k in  10.027478s
        Class method     23.051k (± 3.5%) i/s -    230.895k in  10.028771s

Comparison:
          Direct hit:    26980.7 i/s
       Instantiation:    25128.9 i/s - same-ish: difference falls within error
        Class method:    23051.1 i/s - 1.17x  slower

$ ruby -v ../jruby/blah.rb 
ruby 2.4.1p111 (2017-03-22 revision 58053) [x86_64-darwin16]
Warming up --------------------------------------
       Instantiation     1.718k i/100ms
          Direct hit     1.769k i/100ms
        Class method     1.757k i/100ms
Calculating -------------------------------------
       Instantiation     17.896k (± 4.1%) i/s -    178.672k in  10.000692s
          Direct hit     19.360k (± 4.2%) i/s -    194.590k in  10.069156s
        Class method     17.921k (± 3.3%) i/s -    179.214k in  10.011603s

Comparison:
          Direct hit:    19360.3 i/s
        Class method:    17920.7 i/s - 1.08x  slower
       Instantiation:    17896.1 i/s - same-ish: difference falls within error

Can you show us jruby -v please?

@nightsurge
Copy link
Author

nightsurge commented Dec 20, 2017 •
edited
Loading 

jruby -v
jruby 9.1.13.0 (2.3.3) 2017-09-06 8e1c115 Java HotSpot(TM) 64-Bit Server VM 25.121-b13 on 1.8.0_121-b13 +jit [darwin-x86_64]

jruby -v
jruby 1.7.2 (1.9.3p327) 2013-01-04 302c706 on Java HotSpot(TM) 64-Bit Server VM 1.8.0_121-b13 +indy [darwin-x86_64]

EDIT: Added OS and JRUBY OPTS to original comment

@enebo
Copy link
Member

enebo commented Dec 20, 2017

--debug is the cause of your performance issue. I believe to only run in interpreted mode and we also emit extra trace instrs. Why 1.7.2 does not suffer from this I don't recall but we do not recommend running performance sensitive applications with --debug enabled.

@enebo
Copy link
Member

enebo commented Dec 20, 2017

To show perf difference:

system ~/work/jruby jruby-9.1 1481% jruby -v ../snippets/bench1.rb 
jruby 9.1.15.0 (2.3.3) 2017-12-20 83271e2 OpenJDK 64-Bit Server VM 25.151-b12 on 1.8.0_151-b12 +jit [linux-x86_64]
Warming up --------------------------------------
       Instantiation     1.697k i/100ms
          Direct hit     2.220k i/100ms
        Class method     2.226k i/100ms
Calculating -------------------------------------
       Instantiation     21.405k (± 9.8%) i/s -    212.125k in  10.018731s
          Direct hit     22.619k (± 4.9%) i/s -    226.440k in  10.037539s
        Class method     23.868k (± 7.2%) i/s -    238.182k in  10.037186s

Comparison:
        Class method:    23867.9 i/s
          Direct hit:    22619.3 i/s - same-ish: difference falls within error
       Instantiation:    21405.1 i/s - same-ish: difference falls within error

system ~/work/jruby jruby-9.1 1482% jruby --debug -v ../snippets/bench1.rb 
jruby 9.1.15.0 (2.3.3) 2017-12-20 83271e2 OpenJDK 64-Bit Server VM 25.151-b12 on 1.8.0_151-b12 +jit [linux-x86_64]
Warming up --------------------------------------
       Instantiation   296.000  i/100ms
          Direct hit   327.000  i/100ms
        Class method   306.000  i/100ms
Calculating -------------------------------------
       Instantiation      3.232k (± 9.5%) i/s -     32.264k in  10.083177s
          Direct hit      3.142k (± 9.6%) i/s -     31.392k in  10.089159s
        Class method      3.277k (± 6.1%) i/s -     32.742k in  10.033501s

Comparison:
        Class method:     3276.9 i/s
       Instantiation:     3232.4 i/s - same-ish: difference falls within error
          Direct hit:     3142.0 i/s - same-ish: difference falls within error

We have talked about improving performance of debug by allowing them to JIT but the emits of extra instrs will always make this slower than not emitting those extra instrs.

@nightsurge
Copy link
Author

Wow, thank you for this! This was running locally, was just scared at first from the upgrade!

@enebo enebo reopened this Dec 20, 2017
@enebo enebo changed the title JRuby 9000 performance is 4-5x slower than JRuby 1.7.2 or Ruby 2.3.3 JRuby 9000 performance with --debug is 4-5x slower than JRuby 1.7.2 or Ruby 2.3.3 Dec 20, 2017
@enebo enebo added this to the JRuby 9.1.16.0 milestone Dec 20, 2017
@enebo
Copy link
Member

enebo commented Dec 20, 2017

@nightsurge We will still not recommend running in perf-sensitive modes with --debug but @headius decided to add support for --debug to the JIT. So it will definitely be a lot faster than it currently is on 9k.

headius added a commit that referenced this issue Dec 20, 2017
@headius
Implement TraceInstr in JIT for faster --debug. Fixes #4909.
1fd8a50
@headius
Copy link
Member

headius commented Dec 20, 2017

Fixed in 1fd8a50.

$ jruby -v --debug blah.rb
jruby 9.1.16.0-SNAPSHOT (2.3.3) 2017-12-20 83271e2 Java HotSpot(TM) 64-Bit Server VM 25.131-b11 on 1.8.0_131-b11 +jit [darwin-x86_64]
Warming up --------------------------------------
       Instantiation     2.102k i/100ms
          Direct hit     2.210k i/100ms
        Class method     2.021k i/100ms
Calculating -------------------------------------
       Instantiation     23.466k (± 3.4%) i/s -    235.424k in  10.044442s
          Direct hit     25.542k (± 4.4%) i/s -    256.360k in  10.056545s
        Class method     20.811k (± 3.9%) i/s -    208.163k in  10.018305s

Comparison:
          Direct hit:    25542.4 i/s
       Instantiation:    23465.9 i/s - 1.09x  slower
        Class method:    20810.9 i/s - 1.23x  slower

@headius headius closed this as completed Dec 20, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
performance
Projects
None yet
Milestone
JRuby 9.1.16.0
Development

No branches or pull requests
3 participants
@headius @enebo @nightsurge