I am trying to benchmark an expression using the Criterium library. The expression is
(vec (range 10000000))
To benchmark it i type
(criterium.core/bench (vec (range 10000000)))
and after a while i get
OutOfMemoryError GC overhead limit exceeded java.lang.Long.valueOf (Long.java:840)
As i have seen here this means that the maximum size of the heap (1 GB) is not enough for the data to fit and the garbage collector tries to free space but is unable to do so. However, microbenchmarking the expression like below doesn't produce this error
(dotimes [i 60] (time (vec (range 10000000))))
By the way, i set it to 60 times because i have seen here that the bench macro does 60 executions by default.
The question is why is this happening when using Criterium.
Edit: When starting a fresh repl the code below
{:max (.maxMemory (Runtime/getRuntime)), :total (.totalMemory (Runtime/getRuntime))}
outputs
{:max 922746880, :total 212860928}
After i run (dotimes [i 60] (time (vec (range 10000000)))) or (criterium.core/bench (vec (range 10000000)))
it outputs
{:max 922746880, :total 922746880}
I was able to reproduce the behavior by using this test:
;project.clj
:profiles {:test {:jvm-opts ["-Xms1024m" "-Xmx1024m"]}}
(:require [clojure.test :refer :all]
[criterium.core :as ben])
(deftest ^:focused ben-test
(is (ben/with-progress-reporting
(ben/bench (vec (range 10000000))))))
The stack trace looks like this:
Estimating sampling overhead
Warming up for JIT optimisations 10000000000 ...
compilation occurred before 377618 iterations
...
Estimating execution count ...
Sampling ...
Final GC...
Checking GC...
Finding outliers ...
Bootstrapping ...
Checking outlier significance
Warming up for JIT optimisations 10000000000 ...
compilation occurred before 1 iterations
criterium.core$execute_expr_core_timed_part$fn__40395.invoke (core.clj:370)
criterium.core$execute_expr_core_timed_part.invokeStatic (core.clj:366)
criterium.core$execute_expr_core_timed_part.invoke (core.clj:345)
criterium.core$execute_expr.invokeStatic (core.clj:378)
criterium.core$execute_expr.invoke (core.clj:374)
criterium.core$warmup_for_jit.invokeStatic (core.clj:428)
criterium.core$warmup_for_jit.invoke (core.clj:396)
criterium.core$run_benchmark.invokeStatic (core.clj:479)
criterium.core$run_benchmark.invoke (core.clj:470)
criterium.core$benchmark_STAR_.invokeStatic (core.clj:826)
criterium.core$benchmark_STAR_.invoke (core.clj:812)
We can see here that the error occurs in the JIT-Warning-Up step. The interesting point is the function execute-expr-core-timed-part (core.clj:345). This functions performs the expression (vec (range 10000000)) n times and saves the returned value every time to a so-called mutable place. My hypothesis it that we have the memory leak here.
(time-body
(loop [i (long (dec n))
v (f)]
==> (set-place mutable-place v**)
(if (pos? i)
(recur (unchecked-dec i) (f))
v)))