Graal: Failing to build native-image when using pprint in Clojure 1.10.1 / GraalVM 19.2.0 CE

[GradySimon]

I posted about this here and was asked to file a separate issue. Building a native-image fails when I use clojure.pprint. Using e.g. println instead works fine.

Here's my GraalVM version.

> $ /usr/lib/jvm/graalvm/bin/native-image --version                                                                                   
GraalVM Version 19.2.0 CE

Reproduction steps:

Extract graal-pprint-repro.zip

Then, from inside graal-pprint-repro/

> $ lein do clean, uberjar                                                                                                            
Compiling graal-pprint-repro.core
Created /home/grady/Dropbox/code/repros/graal-pprint-repro/target/uberjar/graal-pprint-repro-0.1.0-SNAPSHOT.jar
Created /home/grady/Dropbox/code/repros/graal-pprint-repro/target/uberjar/graal-pprint-repro-0.1.0-SNAPSHOT-standalone.jar

Or if you don't want to install Clojure and lein, you can skip the above step and just use the standalone jar included in the zip.

```bash

$ /usr/lib/jvm/graalvm/bin/native-image \
--report-unsupported-elements-at-runtime \
--initialize-at-build-time \
--no-fallback --verbose -H:+ReportExceptionStackTraces \
-jar ./target/uberjar/graal-pprint-repro-0.1.0-SNAPSHOT-standalone.jar \
-H:Name=./target/repro

Build on Server(pid: 27912, port: 33569)
SendBuildRequest [
-task=com.oracle.svm.hosted.NativeImageGeneratorRunner
-imagecp
/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/svm/builder/svm.jar:/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/svm/builder/objectfile.jar:/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/svm/builder/llvm-wrapper.jar:/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/svm/builder/svm-llvm.jar:/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/svm/builder/graal-llvm.jar:/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/svm/builder/pointsto.jar:/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/svm/builder/javacpp.jar:/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/svm/builder/llvm-platform-specific.jar:/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/jvmci/jvmci-api.jar:/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/jvmci/graal-management.jar:/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/jvmci/jvmci-hotspot.jar:/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/jvmci/graal.jar:/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/boot/graaljs-scriptengine.jar:/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/boot/graal-sdk.jar:/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/svm/library-support.jar:/home/grady/Dropbox/code/repros/graal-pprint-repro/target/uberjar/graal-pprint-repro-0.1.0-SNAPSHOT-standalone.jar
-H:Path=/home/grady/Dropbox/code/repros/graal-pprint-repro
-H:+ReportUnsupportedElementsAtRuntime
-H:ClassInitialization=:build_time
-H:FallbackThreshold=0
-H:+ReportExceptionStackTraces
-H:Class=graal_pprint_repro.core
-H:CLibraryPath=/usr/lib/jvm/graalvm-ce-linux-amd64-19.2.0/graalvm-ce-19.2.0/jre/lib/svm/clibraries/linux-amd64
-H:Name=./target/repro
]
[./target/repro:27912] classlist: 1,197.90 ms
[./target/repro:27912] (cap): 610.89 ms
[./target/repro:27912] setup: 801.29 ms
[./target/repro:27912] analysis: 8,652.58 ms
Error: unbalanced monitors: mismatch at monitorexit, 96|LoadField#lockee__5436__auto__ != 3|LoadField#lockee__5436__auto__
Detailed message:
Call path from entry point to clojure.spec.gen.alpha$dynaload$fn__2628.invoke():
at clojure.spec.gen.alpha$dynaload$fn__2628.invoke(alpha.clj:21)
at clojure.lang.AFn.run(AFn.java:22)
at java.lang.Thread.run(Thread.java:748)
at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:460)
at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
at com.oracle.svm.core.code.IsolateEnterStub.PosixJavaThreads_pthreadStartRoutine_e1f4a8c0039f8337338252cd8734f63a79b5e3df(generated:0)

com.oracle.svm.core.util.UserError$UserException: unbalanced monitors: mismatch at monitorexit, 96|LoadField#lockee__5436__auto__ != 3|LoadField#lockee__5436__auto__
Detailed message:
Call path from entry point to clojure.spec.gen.alpha$dynaload$fn__2628.invoke():
at clojure.spec.gen.alpha$dynaload$fn__2628.invoke(alpha.clj:21)
at clojure.lang.AFn.run(AFn.java:22)
at java.lang.Thread.run(Thread.java:748)
at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:460)
at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
at com.oracle.svm.core.code.IsolateEnterStub.PosixJavaThreads_pthreadStartRoutine_e1f4a8c0039f8337338252cd8734f63a79b5e3df(generated:0)

at com.oracle.svm.core.util.UserError.abort(UserError.java:75)
at com.oracle.svm.hosted.FallbackFeature.reportAsFallback(FallbackFeature.java:223)
at com.oracle.svm.hosted.NativeImageGenerator.runPointsToAnalysis(NativeImageGenerator.java:737)
at com.oracle.svm.hosted.NativeImageGenerator.doRun(NativeImageGenerator.java:526)
at com.oracle.svm.hosted.NativeImageGenerator.lambda$run$0(NativeImageGenerator.java:444)
at java.util.concurrent.ForkJoinTask$AdaptedRunnableAction.exec(ForkJoinTask.java:1386)
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)

Caused by: com.oracle.graal.pointsto.constraints.UnsupportedFeatureException: unbalanced monitors: mismatch at monitorexit, 96|LoadField#lockee__5436__auto__ != 3|LoadField#lockee__5436__auto__
Detailed message:
Call path from entry point to clojure.spec.gen.alpha$dynaload$fn__2628.invoke():
at clojure.spec.gen.alpha$dynaload$fn__2628.invoke(alpha.clj:21)
at clojure.lang.AFn.run(AFn.java:22)
at java.lang.Thread.run(Thread.java:748)
at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:460)
at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)
at com.oracle.svm.core.code.IsolateEnterStub.PosixJavaThreads_pthreadStartRoutine_e1f4a8c0039f8337338252cd8734f63a79b5e3df(generated:0)

at com.oracle.graal.pointsto.constraints.UnsupportedFeatures.report(UnsupportedFeatures.java:130)
at com.oracle.graal.pointsto.BigBang.finish(BigBang.java:565)
at com.oracle.svm.hosted.NativeImageGenerator.runPointsToAnalysis(NativeImageGenerator.java:688)
... 7 more

Caused by: org.graalvm.compiler.code.SourceStackTraceBailoutException$1: unbalanced monitors: mismatch at monitorexit, 96|LoadField#lockee__5436__auto__ != 3|LoadField#lockee__5436__auto__
at clojure.spec.gen.alpha$dynaload$fn__2628.invoke(alpha.clj:22)
Caused by: org.graalvm.compiler.core.common.PermanentBailoutException: unbalanced monitors: mismatch at monitorexit, 96|LoadField#lockee__5436__auto__ != 3|LoadField#lockee__5436__auto__
at org.graalvm.compiler.java.BytecodeParser.bailout(BytecodeParser.java:3761)
at org.graalvm.compiler.java.BytecodeParser.genMonitorExit(BytecodeParser.java:2703)
at org.graalvm.compiler.java.BytecodeParser.processBytecode(BytecodeParser.java:5136)
at org.graalvm.compiler.java.BytecodeParser.iterateBytecodesForBlock(BytecodeParser.java:3267)
at org.graalvm.compiler.java.BytecodeParser.processBlock(BytecodeParser.java:3074)
at org.graalvm.compiler.java.BytecodeParser.build(BytecodeParser.java:976)
at org.graalvm.compiler.java.BytecodeParser.buildRootMethod(BytecodeParser.java:870)
at org.graalvm.compiler.java.GraphBuilderPhase$Instance.run(GraphBuilderPhase.java:84)
at org.graalvm.compiler.phases.Phase.run(Phase.java:49)
at org.graalvm.compiler.phases.BasePhase.apply(BasePhase.java:197)
at org.graalvm.compiler.phases.Phase.apply(Phase.java:42)
at org.graalvm.compiler.phases.Phase.apply(Phase.java:38)
at com.oracle.graal.pointsto.flow.MethodTypeFlowBuilder.parse(MethodTypeFlowBuilder.java:221)
at com.oracle.graal.pointsto.flow.MethodTypeFlowBuilder.apply(MethodTypeFlowBuilder.java:340)
at com.oracle.graal.pointsto.flow.MethodTypeFlow.doParse(MethodTypeFlow.java:310)
at com.oracle.graal.pointsto.flow.MethodTypeFlow.ensureParsed(MethodTypeFlow.java:300)
at com.oracle.graal.pointsto.flow.MethodTypeFlow.addContext(MethodTypeFlow.java:107)
at com.oracle.graal.pointsto.flow.SpecialInvokeTypeFlow.onObservedUpdate(InvokeTypeFlow.java:421)
at com.oracle.graal.pointsto.flow.TypeFlow.notifyObservers(TypeFlow.java:343)
at com.oracle.graal.pointsto.flow.TypeFlow.update(TypeFlow.java:385)
at com.oracle.graal.pointsto.flow.SourceTypeFlowBase.update(SourceTypeFlowBase.java:121)
at com.oracle.graal.pointsto.BigBang$2.run(BigBang.java:510)
at com.oracle.graal.pointsto.util.CompletionExecutor.lambda$execute$0(CompletionExecutor.java:171)
at java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1402)
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)
Error: Image build request failed with exit status 1
com.oracle.svm.driver.NativeImage$NativeImageError: Image build request failed with exit status 1
at com.oracle.svm.driver.NativeImage.showError(NativeImage.java:1447)
at com.oracle.svm.driver.NativeImage.build(NativeImage.java:1225)
at com.oracle.svm.driver.NativeImage.performBuild(NativeImage.java:1187)
at com.oracle.svm.driver.NativeImage.main(NativeImage.java:1146)

Happy to provide any other information that might useful. As a preview of what's in the zip, here's the project.clj and the core namespace file:

`project.clj`
```clojure
(defproject graal-pprint-repro "0.1.0-SNAPSHOT"
  :description "Demonstrates potential bug with GraalVM and clojure.pprint"
  :license {:name "EPL-2.0 OR GPL-2.0-or-later WITH Classpath-exception-2.0"
            :url "https://www.eclipse.org/legal/epl-2.0/"}
  :dependencies [[org.clojure/clojure "1.10.1"]]
  :main ^:skip-aot graal-pprint-repro.core
  :target-path "target/%s"
  :profiles {:uberjar {:aot :all}})

core.clj

(ns graal-pprint-repro.core
  (:gen-class)
  (:require [clojure.pprint :as pprint]))

(defn -main
  "I don't do a whole lot ... yet."
  [& args]
  (pprint/pprint {:a ["hello" "world"]}))

[djhaskin987]

In an unrelated function, I am hitting a similar problem with native-image on the same line of code, to wit, clojure.spec.gen.alpha$dynaload$fn__2628.invoke (if you look at the stack trace above, it has this in it). I'm thinking this has something to do with clojure.spec . Hope this helps. Still digging into it.

[danielcompton]

There are some related Clojure and GitHub tickets for this: https://github.com/l3nz/cli-matic/issues/64, https://clojure.atlassian.net/browse/CLJ-1472, https://clojure.atlassian.net/browse/CLJ-2482. Downgrading to Clojure 1.9 fixes this issue for me in clojure.spec and clojure.pprint. The issue appears to be related to the locking macro.

[sergeiudris]

+1
experiencing the same issue with nrepl 0.6.0
native-image options: --initialize-at-build-time --report-unsupported-elements-at-runtime

with clojure 1.10.1

Error: unbalanced monitors: mismatch at monitorexit, 3|LoadField#lockee__5436__auto__ != 96|LoadField#lockee__5436__auto__
Call path from entry point to clojure.spec.gen.alpha$dynaload$fn__2628.invoke(): 
...

with clojure 1.9.0

Error: unbalanced monitors: mismatch at monitorexit, 3|LoadField#lockee__5436__auto__ != 441|LoadField#lockee__5436__auto__
Detailed message:
Call path from entry point to nrepl.middleware.session$add_stdin$fn__2385$fn__2389.invoke(): 
...

[cstancu]

I am closing this as it is a clojure bug https://clojure.atlassian.net/browse/CLJ-1472.