Major Clojure 1.10 performance degredation on JDK11
Elana Hashman
ehashman at debian.org
Fri Feb 8 03:39:05 GMT 2019
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? I can't find this documented
anywhere except in this commit[0].
[0]: https://github.com/clojure/clojure/commit/3d9b356306db77946bdf4809baeb660f94cec846
> - 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.
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.
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].
- e
[1]: https://csclub.uwaterloo.ca/~ehashman/debian/clojure/
[2]: https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=877418
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 833 bytes
Desc: not available
URL: <http://alioth-lists.debian.net/pipermail/pkg-clojure-maintainers/attachments/20190207/a004e598/attachment.sig>
More information about the Pkg-clojure-maintainers
mailing list