Timing analysis of Clojure code

Question

Hello Clojure experts,

I am trying to do some timing tests in Clojure 1.3 and I thought I'd ask a question based on an existing piece of code that solves a differential equation that is adapted from this blog post.

Code follows:

;; the differential equation is                                                                                            
;; dy/dt = f(y,t) = t - y                                                                                                  

(defn f [t y] (- t y))

;; solve using Euler's method                                                                                              
(defn solveEuler [t0 y0 h iter]
  (if (> iter 0)
    (let [t1 (+ t0 h)
          y1 (+ y0 (* h (f t0 y0)))]
      (recur t1 y1 h (dec iter)))
    [t0 y0 h iter]))

(defn multipleSolveEuler []
  (let [steps '(1 10 100 1000 10000 100000)
        results (map #(second (solveEuler 0.0 0.0 (/ 1.0 %) %)) steps)
        errors  (map #(- (Math/exp -1) %) results)]
    (partition 3 (interleave steps results errors))))

(def *cpuspeed* 2.0)

(defmacro cyclesperit [expr its]
  `(let [start# (. System (nanoTime))
         ret# ( ~@expr (/ 1.0 ~its) ~its )
         finish# (. System (nanoTime))]
     (int (/ (* *cpuspeed* (- finish# start#)) ~its))))

(defn solveEuler-2 [t0 y0 h its]
  (let [zero (int 0)]
    (loop [t0 (double t0), y0 (double y0), h (double h), its (int its)]
      (if (> its zero)
        (let [t1 (+ t0 h)
              y1 (+ y0 (* h (- t0 y0)))]
          (recur t1 y1 h (dec its)))
        [t0 y0 h its]))))

So when I say

(time solveItEuler-2 0.0 1.0 (/ 1.0 1000000000) 1000000000))

I get a time 6004.184 msecs on a 6 month old Macbook pro. I issue the command again, and I get around the same time. But when I run it 3 other times I get times in the range of 3500 msec. I have noticed this before for other code snippets, and was wondering why this is so. I suppose I would expect a roughly similar execution time across successive runs.

Is it my lack of understanding how "time" works, something I am missing, or some kind of caching happening under the hood?

Thanks.

i think that you should simplify your question and provide a much simpler code snippet. — viebel, Mar 10 '12 at 17:31
Although my question wasn't really about a particular code snippet, but about the results of doing a timing analysis on the JVM, the example above has a "big enough" runtime to see dramatic differences - which is why I chose it. — endbegin, Mar 11 '12 at 19:53

score 7 · Accepted Answer · answered Mar 09 '12 at 20:19

7

It's not time that's relevant, but rather the JVM optimizing the code at runtime. What you observe is typical; execution time will drop and then stabilize after about 3 invocations.

answered Mar 09 '12 at 20:19

Alex Taggart

7,805
28
31

I see. Therefore, in order to do a fairly accurate timing analysis, does one have to run a piece of code multiple times before saying something like "this code takes X secs to run"? – endbegin Mar 09 '12 at 20:27
Precisely. This goes for all languages running on the JVM. Just keep running it until you get stable values. – Alex Taggart Mar 09 '12 at 20:28
could you please provide some material about this behavior of the JVM? – viebel Mar 10 '12 at 17:32
2

@Yehonathan [One ref](http://www.bestinclass.dk/index.php/2010/02/benchmarking-jvm-languages/). [anoth](http://stackoverflow.com/questions/504103/how-do-i-write-a-correct-micro-benchmark-in-java). You want to search on "JVM warmup", "hotspot inlining", -XX:MaxInlineSize" – Gene T Mar 12 '12 at 10:13

score 7 · Answer 2 · answered Mar 11 '12 at 04:59

7

I recommend using the Criterium library for benchmarking. It is designed to deal with the pitfalls of benchmarking code that runs on the JVM.

answered Mar 11 '12 at 04:59

Brian

1,810
12
9

Gene T · Answer 3 · 2012-03-12T10:48:00.783

(This is response to Viebel request for more info, which became too many chars for a single comment, This is not answer to orig. Q).

There are quite a few degrees of freedom: JVM GC and heap settings, startup time, number of warmup runs, data structures used, size of inlined methods.

http://www.infoq.com/articles/java-threading-optimizations-p2

http://groups.google.com/group/clojure/browse_thread/thread/776943086de213f9#

http://stas-blogspot.blogspot.com/2011/07/most-complete-list-of-xx-options-for.html

http://www.azulsystems.com/blog/cliff/2009-09-06-java-vs-c-performanceagain

Timing analysis of Clojure code

3 Answers3