Some code dramatically slower in Clojure 1.3 Alpha 1?

[Btsai]

After updating from Clojure 1.2 to Clojure 1.3 Alpha 1, I noticed that
one of my Project Euler solutions became dramatically slower. The
solution was for Problem 14, finding the number less than N that
produces the longest Collatz sequence.

For N = 100,000, the time required to find the answer was as follows:

Clojure 1.2 = 1327.45 msecs
Clojure 1.3 Alpha 1 = 191186.76 msecs

(For Problem 14, N is actually 1,000,000, but I ran out of patience
waiting for the code to produce the answer in Clojure 1.3 Alpha 1)

Has anyone run into something like this, or know what might have
caused the dramatic difference in speed?

The code:

(defn next-term [n]
(if (even? n) (/ n 2)
(inc (* n 3))))

(defn count-terms [n]
(if (= 1 n) 1
(inc (count-terms (next-term n)))))

(let [pair (juxt identity count-terms)
pairs (map pair (range 1 100000))]
(println (first (apply max-key second pairs))))

Machine specs:

Intel Core 2 Duo T9300 @ 2.5 GHz
2 GB RAM
JVM is running on server mode

P.S. I originally wanted to write that last part of the code a little
more elegantly, like this:

(println (apply max-key count-terms (range 1 100000)))

But that made things even slower:

Clojure 1.2 = 2764.48 msecs
Clojure 1.3 Alpha 1 = 740025.36 msecs

I think I read somewhere that max-key applies f more times than is
necessary, so should not be pass any f that takes significant time to
compute.

[Btsai]

FYI, I tried re-writing count-terms using loop/recur, but it didn't
really make a difference:

(defn count-terms-recur [n]
(loop [n n
count 1]
(cond
(= 1 n) count
(even? n) (recur (/ n 2) (inc count))
:else (recur (inc (* n 3)) (inc count)))))

Clojure 1.2 = 1153.43 msecs
Clojure 1.3 Alpha 1 = 190769.86 msecs

[David Nolen]

(defn next-term [n]

  (if (= (mod n 2) 0) (/ n 2)

      (inc (* n 3))))

(defn count-terms [n]

  (if (= 1 n) 1

      (inc (count-terms (next-term n)))))

(time

 (let [pair (juxt identity count-terms)

       pairs (map pair (range 1 100000))]

   (println (first (apply max-key second pairs)))))

It looks even? is the culprit here. The code above executes in < 1 sec on my machine. 

So it looks like even? needs to repaired to account for the numeric changes.

David

[Nicolas Oury]

After profiling even seems effectively the culprit.
Some method reflector shows up too.

> --
> You received this message because you are subscribed to the Google
> Groups "Clojure" group.
> To post to this group, send email to clo...@googlegroups.com
> Note that posts from new members are moderated - please be patient with your
> first post.
> To unsubscribe from this group, send email to
> clojure+u...@googlegroups.com
> For more options, visit this group at
> http://groups.google.com/group/clojure?hl=en

--
Sent from an IBM Model M, 15 August 1989.

[Nicolas Oury]

Try

(defn even?
"Returns true if n is even, throws an exception if n is not an integer"
{:added "1.0"
:static true}
[n] (zero? (bit-and (long n) (long 1))))

before your example.

It is fast on my computer.
(I believe there is a reflective call, without the explicit cast.)

[Btsai]

David, Nicolas, thank you for finding the culprit so quickly :)

What profiling technique/tool did you use? I have some other code
that is also much slower in 1.3, and thought I'd take a crack at
finding the culprit myself before spamming the list again.

[David Nolen]

On Fri, Sep 24, 2010 at 5:25 PM, Btsai <benny...@gmail.com> wrote:

David, Nicolas, thank you for finding the culprit so quickly :)

What profiling technique/tool did you use?  I have some other code
that is also much slower in 1.3, and thought I'd take a crack at
finding the culprit myself before spamming the list again.

Your code was simple enough for me to make a couple of educated guesses. For more complex code I'd use VisualVM, https://visualvm.dev.java.net/

David 

[Btsai]

Thank you David. Time for me to dig in!

On Sep 24, 3:36 pm, David Nolen <dnolen.li...@gmail.com> wrote:

[Eric Lavigne]

> I think I read somewhere that max-key applies f more times than is
> necessary, so should not be pass any f that takes significant time to
> compute.

Yes, max-key calls f more times than necessary.

http://code.google.com/p/clojure/issues/detail?id=95

We ran into this problem yesterday on a tic-tac-toe project, in which
f was a function that determines who is winning for a given board
position. Tests that previously ran in under a minute now took over 10
minutes (that's roughly how long I waited before stopping it). We
fixed our program by replacing max-key with the alternative
implementation from the above link.

http://github.com/ericlavigne/tic-tac-toe/commit/0d172c45c9d462620af8b819db53e19ab6382bf6

[Nicolas Oury]

> Your code was simple enough for me to make a couple of educated guesses. For
> more complex code I'd use VisualVM, https://visualvm.dev.java.net/
> David
>

I use that too.
Sampling for a first look, profiling with instrumentation for a more
precise answer.
(Here, the sampling gives even? and the profiling gives the reflection methods)

[Btsai]

Thanks Eric :) Have you considered submitting that change as a patch?

> http://github.com/ericlavigne/tic-tac-toe/commit/0d172c45c9d462620af8...

[Btsai]

I went through the rest of my Project Euler code. In addition to
even?, there are some functions in clojure.contrib that are also much
slower in 1.3 Alpha 1.

clojure.contrib.math -> expt

(Clojure 1.2)
user=> (time (doseq [x (range 100000)] (expt x 2)))
"Elapsed time: 119.417971 msecs"

(Clojure 1.3)
user=> (time (doseq [x (range 100000)] (expt x 2)))
"Elapsed time: 10314.24357 msecs"

clojure.contrib.math -> sqrt

(Clojure 1.2)
user=> (time (doseq [x (range 100000)] (sqrt x)))
"Elapsed time: 176.063438 msecs"

(Clojure 1.3)
user=> (time (doseq [x (range 100000)] (sqrt x)))
"Elapsed time: 16323.254492 msecs"

For now, I've switched to using sqrt in the
clojure.contrib.generic.math-functions module (no slow-down in 1.3).
That module also has a pow function, which I was going to use as a
replacement for expt. But pow doesn't seem to handle very large
numbers:

user=> (pow 999 999)
Infinity

So for now I'm using this as a temporary stop-gap:

(defn expt [base pow]
(reduce *' (repeat pow base)))

Also found that sequences from clojure.contrib.lazy-seqs that used to
produce arbitrarily large numbers in 1.2 no longer do so in 1.3:

(Clojure 1.2)
user=> (nth (fibs) 100)
354224848179261915075
user=> (nth (powers-of-2) 100)
1267650600228229401496703205376

(Clojure 1.3)
user=> (nth (fibs) 100)
ArithmeticException integer overflow
clojure.lang.Numbers.throwIntOverflow (Numbers.java:1575)
user=> (nth (powers-of-2) 100)
0

... probably also because of 1.3's changes to numeric operations
(http://dev.clojure.org/display/doc/Enhanced+Primitive+Support).

I guess the take-away is that while playing with 1.3, be prepared to
deal with performance and/or overflow issues when using existing
numeric code (whether your own or someone else's) that doesn't yet
take into account the changes to numeric operations.

[Mark Engelberg]

>> http://code.google.com/p/clojure/issues/detail?id=95

I just looked over this code. You can speed it up even more by
manually encoding the loop, rather than using reduce.
(defn faster-max-key
([k x] x)
([k x & more]
(loop [x x,
kx (k x)
s more]
(if-not s x
(let [y (first s),
ky (k y)]
(if (> kx ky)
(recur x kx (next s))
(recur y ky (next s))))))))

5x faster than the one at the code.google.com link above in my own benchmarks.

[Mark Engelberg]

On Sat, Sep 25, 2010 at 7:02 PM, Btsai <benny...@gmail.com> wrote:
> I went through the rest of my Project Euler code.  In addition to
> even?, there are some functions in clojure.contrib that are also much
> slower in 1.3 Alpha 1.
>
> clojure.contrib.math -> expt
>
>  (Clojure 1.2)
>  user=> (time (doseq [x (range 100000)] (expt x 2)))
>  "Elapsed time: 119.417971 msecs"
>
>  (Clojure 1.3)
>  user=> (time (doseq [x (range 100000)] (expt x 2)))
>  "Elapsed time: 10314.24357 msecs"

Actually, I'd expect that expt would no longer be guaranteed to
produce the right results for large integers in 1.3.
The whole point of clojure.contrib.math is to extend math operations
to the full numeric tower supported by Clojure and 1.3 breaks that.

I haven't tried 1.3 yet, but I'd recommend downloading a copy of
clojure.contrib.math locally and replace any instances of +, -, *,
inc, dec with +', -', *', inc', dec'. This should at least make the
functions produce the correct results. I'd be curious to know whether
performance continues to be bad after making those changes, so if you
do this experiment, please report your results.

--Mark

[Btsai]

Awesome, thanks :)

[Btsai]

> I haven't tried 1.3 yet, but I'd recommend downloading a copy of
> clojure.contrib.math locally and replace any instances of +, -, *,
> inc, dec with +', -', *', inc', dec'.  This should at least make the
> functions produce the correct results.  I'd be curious to know whether
> performance continues to be bad after making those changes, so if you
> do this experiment, please report your results.

I'd be happy to try this out. Will report back later.

[Btsai]

I found that even without patching, most functions in
clojure.contrib.math already correctly handle big nums in 1.3:

Handles big nums in 1.3?
abs Yes
ceil Yes
exact-integer-sqrt No
expt No
floor Yes
gcd Yes
lcm Yes
round No
sqrt Yes

After patching the code to use +', -', *', inc', and dec', expt
handled big nums correctly as well. However, exact-integer-sqrt and
round still didn't.

math=> (exact-integer-sqrt 234523454564564565435456456456)
IllegalArgumentException No method in multimethod 'integer-length' for
dispatch value: class clojure.lang.BigInt clojure.lang.MultiFn.getFn
(MultiFn.java:121)

math=> (round 23450928345029834502983450283405.1)
9223372036854775807

exact-integer-sqrt appears to need the integer-length multi-method to
support the new clojure.lang.BigInt class. I'm guessing that's also
why round is returning an incorrect result; since there's currently no
case for clojure.lang.BigInt, it's falling through to the default of
using Math/round, leading to truncation.

Just replacing +, -, *, inc, dec with +', -', *', inc', and dec' did
not result in any performance gains.

I didn't want to clutter up this email with my test code, but if
anyone wishes to see the code I used, just let me know.

[Mark Engelberg]

Thanks for the info. I'd need to research how clojure.lang.BigInt
differs from java.math.BigInteger, but I'm sure that adding the extra
case for BigInt in the multimethods wouldn't be too hard.

I'm still stumped as to why expt and sqrt would be 100x slower. My
first thought is that the loop/recur machinery has changed in 1.3, to
support primitives in the recur, so perhaps there's some extra back
and forth boxing/unboxing going on, or perhaps loop/recur is just
fundamentally slower now? Another possibility is that all the literal
numbers are now longs instead of Integers, so maybe that's slowing
down the computations?

I'd be curious to know whether explicitly boxing everything in the
second line of expt-int helps the performance at all (along with the '
math operators), i.e.,

(defn- expt-int [base pow]
(loop [n pow, y (num 1), z base]

to

(defn- expt-int [base pow]
(loop [n (num pow), y (num 1), z (num base)]

[Btsai]

Hi Mark,

I tested the change to expt-int. Unfortunately, still no performance
gain.

I'm afraid I don't have a solid enough grasp of Clojure to know what
tweaks are needed to get performance fast again. Do you think you'll
have time to play with 1.3 soon?

[Mark Engelberg]

I believe the performance problems boil down to the abysmal
performance of bit-shift-right and bit-and in Clojure 1.3 alpha 1.
I'll post this in a separate thread to make sure it gets read.

[Mark Engelberg]

As a side note, I notice that in clojure 1.3, bit-shift-left now
provides wraparound logic with no warning if the first input is a long
(as opposed to a bigint).

Wouldn't it be more consistent if bit-shift-left provided an overflow
error for long inputs that shift so much they overflow? Should there
also be an unchecked-bit-shift-left and a bit-shift-left' ?