Major Clojure 1.10 performance degredation on JDK11

[Alex Miller]

On Thu, Feb 7, 2019 at 9:39 PM Elana Hashman <ehashman at debian.org> wrote:

> On Tue, Feb 05, 2019 at 11:42:32PM -0600, Alex Miller wrote:
> >
> > Some things I would look at:
> >
> > - Try with -Dclojure.spec.skip-macros=true to see if any difference
> >   (skips spec macro checking which could possibly affect startup time)
>
> Is this a runtime or build arugment?


It is a compiler flag (really used during macroexpansion specifically) but
compilation happens any time you are compiling code, which can be at
runtime, depending what that means.


> I can't find this documented
> anywhere except in this commit[0].
>
> [0]:
> https://github.com/clojure/clojure/commit/3d9b356306db77946bdf4809baeb660f94cec846


At the moment, only here:
https://clojure.org/guides/faq#skip_macros

But there will be a spec reference page eventually which is where it will
go.

> - Check that you're actually using AOT'ed Clojure. In the clojure jar
> >   file, typically you'll see both .class and .clj files. The timestamps
> >   matter! If the .clj is newer than the .class files, it will use the
> >   .clj and recompile. I have certainly seen people run into this kind of
> >   problem with builds that don't retain timestamps properly for whatever
> >   reason (the Maven shade plugin is a notorious culprit, but we don't
> >   use that in the Clojure build).
>
> So I think I found one fishy looking thing: while clojure.jar's
> timestamps are all fine, it appears that the core.specs.alpha and
> spec.alpha jars have .clj files with identical timestamps to the source
> files, which may be affecting things. Ditto clojure1.8, etc. I believe
> this is due to Debian's reproducible build steps.
>

If timestamps are identical, Clojure will recompile (that is .class is used
only if newer, not same, than .clj file).

We intentionally don't compile or distribute classes in the
core.specs.alpha artifact so that the spec instances are not tied to a
specific version of spec.alpha (which can be updated independently from
clojure). So that artifact should be source only (.clj), no .classes.

How are these things built? Are they using the same process we use to
create the official artifacts? If not, why not? It disturbs me that these
are alternate, potentially bad, versions of things we publish officially.


> However, that doesn't explain the massive slowdown between JDK8 and
> JDK11 for all Clojure jars, 1.8 included.
>
> elana at debian:/debian/clojure$ time
> /usr/lib/jvm/java-8-openjdk-amd64/bin/java -cp
> /usr/share/java/clojure-1.8.jar clojure.main -e '"hi"'
> "hi"
>
> real    0m4.368s
> user    0m13.633s
> sys     0m0.360s
>
> elana at debian:/debian/clojure$ time
> /usr/lib/jvm/java-8-openjdk-amd64/bin/java -cp
> /usr/share/java/clojure-1.8.jar clojure.main -e '"hi"'
> "hi"
>
> real    0m3.941s
> user    0m13.516s
> sys     0m0.356s
>
> elana at debian:/debian/clojure$ time
> /usr/lib/jvm/java-11-openjdk-amd64/bin/java -cp
> /usr/share/java/clojure-1.8.jar clojure.main -e '"hi"'
> "hi"
>
> real    0m9.962s
> user    0m24.804s
> sys     0m0.507s
>
> elana at debian:/debian/clojure$ time
> /usr/lib/jvm/java-11-openjdk-amd64/bin/java -cp
> /usr/share/java/clojure-1.8.jar clojure.main -e '"hi"'
> "hi"
>
> real    0m10.040s
> user    0m26.233s
> sys     0m0.586s
>
>
> I'm finding this utterly baffling.
>
> For comparison, on the same machine I downloaded the official 1.8
> release, and it's not seeing the same performance issues:
>
> elana at debian:/tmp$ time /usr/lib/jvm/java-11-openjdk-amd64/bin/java -cp
> clojure-1.8.0.jar clojure.main -e '"hi"'
> "hi"
>
> real    0m1.377s
> user    0m2.652s
> sys     0m0.155s
> elana at debian:/tmp$ time /usr/lib/jvm/java-8-openjdk-amd64/bin/java -cp
> clojure-1.8.0.jar clojure.main -e '"hi"'
> "hi"
>
> real    0m1.232s
> user    0m2.048s
> sys     0m0.124s
>
>
> Another data point: clj 1.10 linked with the Debian core.specs.alpha and
> spec.alpha:
>
> elana at debian:/tmp$ time /usr/lib/jvm/java-8-openjdk-amd64/bin/java -cp
> clojure-1.10.0.jar:/usr/share/maven-repo/org/clojure/spec.alpha/debian/spec.alpha-debian.jar:/usr/share/maven-repo/org/clojure/core.specs.alpha/debian/core.specs.alpha-debian.jar
> clojure.main -e '"hi"'
> "hi"
>
> real    0m2.761s
> user    0m7.836s
> sys     0m0.317s
> elana at debian:/tmp$ time /usr/lib/jvm/java-11-openjdk-amd64/bin/java -cp
> clojure-1.10.0.jar:/usr/share/maven-repo/org/clojure/spec.alpha/debian/spec.alpha-debian.jar:/usr/share/maven-repo/org/clojure/core.specs.alpha/debian/core.specs.alpha-debian.jar
> clojure.main -e '"hi"'
> "hi"
>
> real    0m4.363s
> user    0m14.337s
> sys     0m0.381s
>
> vs. upstream specs, which it is faster with:
>
> elana at debian:/tmp$ time /usr/lib/jvm/java-11-openjdk-amd64/bin/java -cp
> clojure-1.10.0.jar:core.specs.alpha-0.2.44.jar:spec.alpha-0.2.176.jar
> clojure.main -e '"hi"'
> "hi"
>
> real    0m1.688s
> user    0m3.741s
> sys     0m0.173s
> elana at debian:/tmp$ time /usr/lib/jvm/java-8-openjdk-amd64/bin/java -cp
> clojure-1.10.0.jar:core.specs.alpha-0.2.44.jar:spec.alpha-0.2.176.jar
> clojure.main -e '"hi"'
> "hi"
>
> real    0m1.446s
> user    0m2.752s
> sys     0m0.166s
>
>
> This strongly suggests to me that something different happening in the
> Debian build process is causing a performance degradation.
>

I concur.


>
> Debian's up-to-date core.specs.alpha and spec.alpha are in the archive,
> but in case anyone wants to poke around with the guts of the jars I
> built/are installed in the archive[1].
>
> Note that the terrible performance times I'm seeing here look similar to
> what Rob reported when we had an issue with reproducible builds
> affecting Clojure performance[2].
>

I think it's almost certainly this issue with clj / class timestamps.
afaik, nothing was ever filed about this in the Clojure ticket system.


>
> - e
>
> [1]: https://csclub.uwaterloo.ca/~ehashman/debian/clojure/
> [2]: https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=877418
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://alioth-lists.debian.net/pipermail/pkg-clojure-maintainers/attachments/20190208/5a472054/attachment.html>