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.

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

`n ** m` is slow #3818

Closed
phluid61 opened this Issue Apr 20, 2016 · 7 comments

Comments

Projects
None yet
3 participants
@phluid61
Contributor

phluid61 commented Apr 20, 2016

Environment

  • jruby 9.0.5.0 (2.2.3) 2016-04-20 fffffff OpenJDK 64-Bit Server VM 24.95-b01 on 1.7.0_95-b00 +jit [linux-amd64]
  • Linux example.org 3.16.0-70-generic #90~14.04.1-Ubuntu SMP Wed Apr 6 22:56:34 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux

Expected Behavior

** should have comparable benchmark for Integers as *

Actual Behavior

Benchmarks show ** is an order of magnitude slower than * for Integers, and Integer ** Integer is slower than Float ** Integer

test.rb:

require 'benchmark'

$r = 1_000_000

Benchmark.bmbm do |x|
  x.report('1') { $r.times { 3 ** 3 }}
  x.report('2') { $r.times { 3.0 ** 3 }}
  x.report('3') { $r.times { 3 * 3 * 3 }}
end

MRI:

ruby 2.3.0p0 (2015-12-25 revision 53290) [x86_64-linux]
Rehearsal -------------------------------------
1   0.060000   0.000000   0.060000 (  0.059568)
2   0.110000   0.000000   0.110000 (  0.105355)
3   0.050000   0.000000   0.050000 (  0.055801)
---------------------------- total: 0.220000sec

        user     system      total        real
1   0.070000   0.000000   0.070000 (  0.061776)
2   0.100000   0.000000   0.100000 (  0.104227)
3   0.060000   0.000000   0.060000 (  0.054408)

jruby:

jruby 9.0.5.0 (2.2.3) 2016-04-20 fffffff OpenJDK 64-Bit Server VM 24.95-b01 on 1.7.0_95-b00 +jit [linux-amd64]
Rehearsal -------------------------------------
1   0.520000   0.020000   0.540000 (  0.323665)
2   0.150000   0.000000   0.150000 (  0.115306)
3   0.050000   0.000000   0.050000 (  0.038388)
---------------------------- total: 0.740000sec

        user     system      total        real
1   0.210000   0.020000   0.230000 (  0.191466)
2   0.100000   0.000000   0.100000 (  0.094042)
3   0.020000   0.000000   0.020000 (  0.024104)

Originally reported here

@phluid61

This comment has been minimized.

Show comment
Hide comment
@phluid61

phluid61 Apr 21, 2016

Contributor

Appears to be because there are so many BigInteger allocations/operations in the int_pow function in Numeric.java

Demonstrated by this hack:

diff --git a/core/src/main/java/org/jruby/util/Numeric.java b/core/src/main/java/org/jruby/util/Numeric.java
index cab2ebe..087aa32 100644
--- a/core/src/main/java/org/jruby/util/Numeric.java
+++ b/core/src/main/java/org/jruby/util/Numeric.java
@@ -507,6 +507,9 @@ public class Numeric {
                 y >>= 1;
             }

+            if (z * x > z) {
+                z *= x;
+            } else {
             BigInteger bigX = BigInteger.valueOf(x);
             BigInteger bigXZ = bigX.multiply(bigX);
             if (bigXZ.divide(bigX).longValue() != z) {
@@ -515,6 +518,7 @@ public class Numeric {
                 return v;
             }
             z = bigXZ.longValue();
+            }
         } while(--y != 0);
         if (neg) z = -z;
         return RubyFixnum.newFixnum(runtime, z);

output:

jruby 9.1.0.0 (2.3.0) 2016-04-20 4d42371 OpenJDK 64-Bit Server VM 24.95-b01 on 1.7.0_95-b00 +jit [linux-x86_64]
Rehearsal -------------------------------------
1   0.120000   0.010000   0.130000 (  0.080799)
2   0.180000   0.000000   0.180000 (  0.128503)
3   0.050000   0.000000   0.050000 (  0.038776)
---------------------------- total: 0.360000sec

        user     system      total        real
1   0.030000   0.010000   0.040000 (  0.027987)
2   0.090000   0.000000   0.090000 (  0.096165)
3   0.030000   0.000000   0.030000 (  0.025442)
Contributor

phluid61 commented Apr 21, 2016

Appears to be because there are so many BigInteger allocations/operations in the int_pow function in Numeric.java

Demonstrated by this hack:

diff --git a/core/src/main/java/org/jruby/util/Numeric.java b/core/src/main/java/org/jruby/util/Numeric.java
index cab2ebe..087aa32 100644
--- a/core/src/main/java/org/jruby/util/Numeric.java
+++ b/core/src/main/java/org/jruby/util/Numeric.java
@@ -507,6 +507,9 @@ public class Numeric {
                 y >>= 1;
             }

+            if (z * x > z) {
+                z *= x;
+            } else {
             BigInteger bigX = BigInteger.valueOf(x);
             BigInteger bigXZ = bigX.multiply(bigX);
             if (bigXZ.divide(bigX).longValue() != z) {
@@ -515,6 +518,7 @@ public class Numeric {
                 return v;
             }
             z = bigXZ.longValue();
+            }
         } while(--y != 0);
         if (neg) z = -z;
         return RubyFixnum.newFixnum(runtime, z);

output:

jruby 9.1.0.0 (2.3.0) 2016-04-20 4d42371 OpenJDK 64-Bit Server VM 24.95-b01 on 1.7.0_95-b00 +jit [linux-x86_64]
Rehearsal -------------------------------------
1   0.120000   0.010000   0.130000 (  0.080799)
2   0.180000   0.000000   0.180000 (  0.128503)
3   0.050000   0.000000   0.050000 (  0.038776)
---------------------------- total: 0.360000sec

        user     system      total        real
1   0.030000   0.010000   0.040000 (  0.027987)
2   0.090000   0.000000   0.090000 (  0.096165)
3   0.030000   0.000000   0.030000 (  0.025442)
@phluid61

This comment has been minimized.

Show comment
Hide comment
@phluid61

phluid61 Apr 21, 2016

Contributor

Incidentally, I can't provide a proper PR/patch, because I'm totally lost by this logic around the x/y/z values:

            BigInteger bigX = BigInteger.valueOf(x);
            BigInteger bigXZ = bigX.multiply(bigXZ); /* is this right? */
            if (bigXZ.divide(bigX).longValue() != z) {
                /* .. */
            }
            z = bigXZ.longValue();

In pseudocode this is:

xz = x * x   #?
if (xz / x != z)  # ?? (x*x)/x==x, no? so this is: if (x != z)
  # ...
end
z = xz  # z = x*x? I expected z = x*z

I can't work out what that if statement is meant to be testing; either x!=z, or z!=z. Is it some sort of overflow check I can't comprehend?

Is this the real cause of the slowdown?

Contributor

phluid61 commented Apr 21, 2016

Incidentally, I can't provide a proper PR/patch, because I'm totally lost by this logic around the x/y/z values:

            BigInteger bigX = BigInteger.valueOf(x);
            BigInteger bigXZ = bigX.multiply(bigXZ); /* is this right? */
            if (bigXZ.divide(bigX).longValue() != z) {
                /* .. */
            }
            z = bigXZ.longValue();

In pseudocode this is:

xz = x * x   #?
if (xz / x != z)  # ?? (x*x)/x==x, no? so this is: if (x != z)
  # ...
end
z = xz  # z = x*x? I expected z = x*z

I can't work out what that if statement is meant to be testing; either x!=z, or z!=z. Is it some sort of overflow check I can't comprehend?

Is this the real cause of the slowdown?

@enebo

This comment has been minimized.

Show comment
Hide comment
@enebo

enebo Apr 21, 2016

Member

@phluid61 yeah seems like this should be z and not x. Because of that we seem to always going the Bignum algo at that point which will be slow. In MRI,

            if (MUL_OVERFLOW_FIXNUM_P(x, z)) {
        goto bignum;
        }

So this logic is meant to be a replacement for MRI's overflow check. When I change this to use BigInteger.valueOf(z) we double in speed and avoid going down biginteger path but then we fail one boundary test in ruby/spec.

Member

enebo commented Apr 21, 2016

@phluid61 yeah seems like this should be z and not x. Because of that we seem to always going the Bignum algo at that point which will be slow. In MRI,

            if (MUL_OVERFLOW_FIXNUM_P(x, z)) {
        goto bignum;
        }

So this logic is meant to be a replacement for MRI's overflow check. When I change this to use BigInteger.valueOf(z) we double in speed and avoid going down biginteger path but then we fail one boundary test in ruby/spec.

@enebo enebo closed this in 1e2c561 Apr 21, 2016

@enebo

This comment has been minimized.

Show comment
Hide comment
@enebo

enebo Apr 21, 2016

Member

Ok I basically ported MRI's overflow check. Numbers...Before:

jruby ../snippets/pow1.rb 
Warming up --------------------------------------
                   1     1.000  i/100ms
                   2     1.000  i/100ms
                   3     2.000  i/100ms
Calculating -------------------------------------
                   1      3.245  (± 0.0%) i/s -     33.000 
                   2      8.370  (± 0.0%) i/s -     84.000 
                   3     24.368  (± 4.1%) i/s -    244.000 

After:

jruby ../snippets/pow1.rb 
Warming up --------------------------------------
                   1     1.000  i/100ms
                   2     1.000  i/100ms
                   3     2.000  i/100ms
Calculating -------------------------------------
                   1     16.126  (± 6.2%) i/s -    161.000 
                   2      8.094  (±12.4%) i/s -     81.000 
                   3     25.796  (± 3.9%) i/s -    258.000 

Compared to MRI 2.3:

mri23 ../snippets/pow1.rb 
Warming up --------------------------------------
                   1     1.000  i/100ms
                   2     1.000  i/100ms
                   3     1.000  i/100ms
Calculating -------------------------------------
                   1     10.508  (± 0.0%) i/s -    105.000 
                   2      8.533  (± 0.0%) i/s -     86.000 
                   3     11.240  (± 0.0%) i/s -    113.000 
Member

enebo commented Apr 21, 2016

Ok I basically ported MRI's overflow check. Numbers...Before:

jruby ../snippets/pow1.rb 
Warming up --------------------------------------
                   1     1.000  i/100ms
                   2     1.000  i/100ms
                   3     2.000  i/100ms
Calculating -------------------------------------
                   1      3.245  (± 0.0%) i/s -     33.000 
                   2      8.370  (± 0.0%) i/s -     84.000 
                   3     24.368  (± 4.1%) i/s -    244.000 

After:

jruby ../snippets/pow1.rb 
Warming up --------------------------------------
                   1     1.000  i/100ms
                   2     1.000  i/100ms
                   3     2.000  i/100ms
Calculating -------------------------------------
                   1     16.126  (± 6.2%) i/s -    161.000 
                   2      8.094  (±12.4%) i/s -     81.000 
                   3     25.796  (± 3.9%) i/s -    258.000 

Compared to MRI 2.3:

mri23 ../snippets/pow1.rb 
Warming up --------------------------------------
                   1     1.000  i/100ms
                   2     1.000  i/100ms
                   3     1.000  i/100ms
Calculating -------------------------------------
                   1     10.508  (± 0.0%) i/s -    105.000 
                   2      8.533  (± 0.0%) i/s -     86.000 
                   3     11.240  (± 0.0%) i/s -    113.000 

@enebo enebo added this to the JRuby 9.1.0.0 milestone Apr 21, 2016

@phluid61

This comment has been minimized.

Show comment
Hide comment
@phluid61

phluid61 Apr 21, 2016

Contributor

👍

Contributor

phluid61 commented Apr 21, 2016

👍

@enebo

This comment has been minimized.

Show comment
Hide comment
@enebo

enebo Apr 21, 2016

Member

@phluid61 Thanks for bringing this to light. Almost makes me want to generate some microbenches against other numeric operations to see if we have other issues.

Member

enebo commented Apr 21, 2016

@phluid61 Thanks for bringing this to light. Almost makes me want to generate some microbenches against other numeric operations to see if we have other issues.

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Apr 22, 2016

Member
Member

headius commented Apr 22, 2016

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment