Odd perf variations

[mfikes]

(with-out-str (time (apply + (range 1e8)))) runs slower and slower in Planck (but sometimes faster), but not in Safari with http://clojurescript.io

There is also variation you can see when doing things at the top level vs wrapping them in a dotimes.

Perhaps this is related to memory pressure, but it would be nice to sort out what it is, especially since JavaScriptCore in Safari doesn't exhibit the issue.

Perhaps Planck is leaking something or holding onto something in the JS engine.

[cgrand]

The system-time monkey patching is not the cause, the slowdown occurs even without the time call:

cljs.user=> (defn bench [] (identity (dotimes [_ 10000] (group-by odd? (range 256)))))
#'cljs.user/bench
cljs.user=> (time (bench))"Elapsed time: 1448.696354 msecs"
nil
cljs.user=> (bench)nil
cljs.user=> (bench)
nil
cljs.user=> (bench)
nil
cljs.user=> (bench)
nil
cljs.user=> (bench)
nil
cljs.user=> (bench)
nil
cljs.user=> (bench)
nil
cljs.user=> (bench)
nil
cljs.user=> (time (bench))
"Elapsed time: 4086.109717 msecs"
nil

It's certainly related to optimization as loops starting in "slow" mode tend to regain their original speed.

[mfikes]

I think it is possible to reproduce something similar directly in JavaScriptCore (without Planck) with these functions:

function numberSum(N) {
  var total = 0;
    for(var i = 1; i <= N; i++){
      total += i;
    }
    return total;
}

function timeCount(N) {
  var start = Date.now();
  numberSum(N);
  return Date.now() - start;
}

Here, using jsc:

$ jsc
>>> function numberSum(N) {
...   var total = 0;
...     for(var i = 1; i <= N; i++){
...       total += i;
...     }
...     return total;
... }
undefined
>>>
undefined
>>> function timeCount(N) {
...   var start = Date.now();
...   numberSum(N);
...   return Date.now() - start;
... }
undefined
>>> timeCount(1e9)
868
>>> timeCount(1e9)
864
>>> timeCount(1e9)
875
>>> timeCount(1e9)
871
>>> timeCount(1e9)
859
>>> timeCount(1e9)
867
>>> timeCount(1e9)
863
>>> timeCount(1e9)
890
>>> timeCount(1e9)
950
>>> timeCount(1e9)
1187
>>> timeCount(1e9)
2015
>>> timeCount(1e9)
868
>>> timeCount(1e9)
3387
>>> timeCount(1e9)
2686
>>> timeCount(1e9)
871
>>> timeCount(1e9)
3381
>>> timeCount(1e9)
3413
>>> timeCount(1e9)
3516
>>>

Note that, on this same box:

$ planck -q
cljs.user=> (time (apply + (range 1e9)))
"Elapsed time: 866.124949 msecs"
499999999067109000

So, it appears that the loops initially have the same perf (essentially native; see https://youtu.be/LopU-kMpe8I )

While Planck is much more pronounced in the slowdown, jsc seems to exhibit somewhat the same behavior.

I also tried sampling Planck on macOS and it seems to be in FTL methods when it slows down.

[mfikes]

If you try the above experiments with jsc --useFTLJIT=false you can replicate the predictable behavior seen in http://clojurescript.io

[pyrmont]

I tried running the same code as in @cgrand's example and see no comparable slowdown in Planck 2.21.0 (compiled with version 2.18.6 of libjavascriptcoregtk-4.0-dev on Debian 9).

cljs.user=> (defn bench [] (identity (dotimes [_ 10000] (group-by odd? (range 256)))))
#'cljs.user/bench
cljs.user=> (time (bench))
"Elapsed time: 1169.457557 msecs"
nil
cljs.user=> (bench)
nil
cljs.user=> (bench)
nil
cljs.user=> (bench)
nil
cljs.user=> (bench)
nil
cljs.user=> (bench)
nil
cljs.user=> (bench)
nil
cljs.user=> (bench)
nil
cljs.user=> (bench)
nil
cljs.user=> (time (bench))
"Elapsed time: 1121.371456 msecs"
nil
cljs.user=>