What kind of optimization does the Clojure REPL perform for this block of code?

Question

I thought I would build a stupid non-recursive version of the multiplication function and see how it compares with the corresponding TCO. However, I noticed that both in REPL (I use Emacs with java -cp <classpath> clojure.main configured for inferior-lisp ), and when the program is called from the command line, some kind of optimization / memoization seems to be happening. In fact, the results are more pronounced in REPL.

 (defn mult-silly [nm] (if (> n 0) (+ m (mult-silly (dec n) m)) 0)) (dotimes [_ 5] (println (time (mult-silly 5000 4)))) 

The above issues on REPL:

user => # 'user / mult-dumb
user => "Elapsed time: 10.697919 msecs"
20000
"Elapsed time: 3.069106 msecs"
20000
"Elapsed time: 2.301474 msecs"
20000
"Elapsed time: 1.285696 msecs"
20000
"Elapsed time: 0.585541 ms"
20000

Any idea why I see this?

Answer 1

As @MariusDanila noted in his comment, this is because the JIT is kicking.

To verify this, you can run java with the -Xint option, which forces it to run the mode only for interpretation, so nothing is compiled into its own code (and, of course, there are no optimizations performed with this native code).

So here is what I got java:

 "Elapsed time: 4.175 msecs" 20000 "Elapsed time: 2.548 msecs" 20000 "Elapsed time: 7.746 msecs" 20000 "Elapsed time: 1.919 msecs" 20000 "Elapsed time: 1.72 msecs" 20000 

Note that here the time has actually increased for the third run. I assume this is due to compilation happening at the same time. Whereas with -Xint :

 "Elapsed time: 31.463 msecs" 20000 "Elapsed time: 30.844 msecs" 20000 "Elapsed time: 30.643 msecs" 20000 "Elapsed time: 29.972 msecs" 20000 "Elapsed time: 30.617 msecs" 20000 

As you can see from the second example, there is no acceleration.

This is why Rule 1 for micro-detection should always exclude warm-up time from your measurements.