Quarkus: Quarkus hello.world image build fails when using openjdk-8u252-jvmci-20.0-b03

[olpaw]

Describe the bug

Building a Quarkus hello.world image fails when using a GraalVM built from https://github.com/graalvm/graal-jvmci-8/releases/download/jvmci-20.0-b03/openjdk-8u252-jvmci-20.0-b03-linux-amd64.tar.gz

[INFO] --- maven-jar-plugin:2.4:jar (default-jar) @ hello.world ---
[INFO] Building jar: /home/pwoegere/OLabs/issues/GR-21959/hello.world/target/hello.world-1.0-SNAPSHOT.jar
[INFO] 
[INFO] --- quarkus-maven-plugin:1.2.0.Final:build (default) @ hello.world ---
[INFO] [org.jboss.threads] JBoss Threads version 3.0.0.Final
[INFO] [io.quarkus.deployment.pkg.steps.JarResultBuildStep] Building thin jar: /home/pwoegere/OLabs/issues/GR-21959/hello.world/target/hello.world-1.0-SNAPSHOT-runner.jar
[INFO] [io.quarkus.deployment.QuarkusAugmentor] Quarkus augmentation completed in 1055ms
[INFO] 
[INFO] --- quarkus-maven-plugin:1.2.0.Final:native-image (default) @ hello.world ---
[INFO] [io.quarkus.deployment.pkg.steps.JarResultBuildStep] Building native image source jar: /home/pwoegere/OLabs/issues/GR-21959/hello.world/target/hello.world-1.0-SNAPSHOT-native-image-source-jar/hello.world-1.0-SNAPSHOT-runner.jar
[INFO] [io.quarkus.deployment.pkg.steps.NativeImageBuildStep] Building native image from /home/pwoegere/OLabs/issues/GR-21959/hello.world/target/hello.world-1.0-SNAPSHOT-native-image-source-jar/hello.world-1.0-SNAPSHOT-runner.jar
[INFO] [io.quarkus.deployment.pkg.steps.NativeImageBuildStep] Running Quarkus native-image plugin on GraalVM Version 20.1.0-dev LIBGRAAL (Java Version 1.8.0_252)
[INFO] [io.quarkus.deployment.pkg.steps.NativeImageBuildStep] /home/pwoegere/OLabs/issues/GR-21959/graal/vm/latest_graalvm_home/bin/native-image -J-Djava.util.logging.manager=org.jboss.logmanager.LogManager -J-Dsun.nio.ch.maxUpdateArraySize=100 -J-Dio.netty.leakDetection.level=DISABLED -J-Dio.netty.allocator.maxOrder=1 -J-Dvertx.logger-delegate-factory-class-name=io.quarkus.vertx.core.runtime.VertxLogDelegateFactory -J-Dvertx.disableDnsResolver=true --initialize-at-build-time= -H:InitialCollectionPolicy=com.oracle.svm.core.genscavenge.CollectionPolicy$BySpaceAndTime -jar hello.world-1.0-SNAPSHOT-runner.jar -H:FallbackThreshold=0 -H:+ReportExceptionStackTraces -H:-AddAllCharsets -H:EnableURLProtocols=http -H:NativeLinkerOption=-no-pie -H:+JNI --no-server -H:-UseServiceLoaderFeature -H:+StackTrace hello.world-1.0-SNAPSHOT-runner
[hello.world-1.0-SNAPSHOT-runner:47922]    classlist:   4,574.43 ms,  1.36 GB
[hello.world-1.0-SNAPSHOT-runner:47922]        (cap):     653.05 ms,  1.36 GB
[hello.world-1.0-SNAPSHOT-runner:47922]        setup:   2,072.65 ms,  1.36 GB
15:10:54,309 INFO  [org.jbo.threads] JBoss Threads version 3.0.0.Final
[hello.world-1.0-SNAPSHOT-runner:47922]     (clinit):     582.35 ms,  1.95 GB
[hello.world-1.0-SNAPSHOT-runner:47922]   (typeflow):  11,011.49 ms,  1.95 GB
[hello.world-1.0-SNAPSHOT-runner:47922]    (objects):   8,593.85 ms,  1.95 GB
[hello.world-1.0-SNAPSHOT-runner:47922]   (features):     388.07 ms,  1.95 GB
[hello.world-1.0-SNAPSHOT-runner:47922]     analysis:  21,522.86 ms,  1.95 GB
Error: Unsupported features in 4 methods
Detailed message:
Error: Class initialization of io.netty.handler.ssl.JettyAlpnSslEngine$ClientEngine failed. Use the option --initialize-at-run-time=io.netty.handler.ssl.JettyAlpnSslEngine$ClientEngine to explicitly request delayed initialization of this class.
Original exception that caused the problem: java.lang.NoClassDefFoundError: org/eclipse/jetty/alpn/ALPN$Provider
    at sun.misc.Unsafe.ensureClassInitialized(Native Method)
    at com.oracle.svm.hosted.classinitialization.ConfigurableClassInitialization.ensureClassInitialized(ConfigurableClassInitialization.java:167)
    at com.oracle.svm.hosted.classinitialization.ConfigurableClassInitialization.computeInitKindAndMaybeInitializeClass(ConfigurableClassInitialization.java:560)
    at com.oracle.svm.hosted.classinitialization.ConfigurableClassInitialization.computeInitKindAndMaybeInitializeClass(ConfigurableClassInitialization.java:130)
    at com.oracle.svm.hosted.classinitialization.ConfigurableClassInitialization.maybeInitializeHosted(ConfigurableClassInitialization.java:158)
    at com.oracle.svm.hosted.SVMHost.registerType(SVMHost.java:200)
    at com.oracle.graal.pointsto.meta.AnalysisUniverse.createType(AnalysisUniverse.java:264)
    at com.oracle.graal.pointsto.meta.AnalysisUniverse.lookupAllowUnresolved(AnalysisUniverse.java:205)
    at com.oracle.graal.pointsto.infrastructure.WrappedConstantPool.lookupType(WrappedConstantPool.java:155)
    at org.graalvm.compiler.java.BytecodeParser.lookupType(BytecodeParser.java:4248)
    at org.graalvm.compiler.java.BytecodeParser.genNewInstance(BytecodeParser.java:4505)
    at org.graalvm.compiler.java.BytecodeParser.processBytecode(BytecodeParser.java:5303)
    at org.graalvm.compiler.java.BytecodeParser.iterateBytecodesForBlock(BytecodeParser.java:3397)
    at org.graalvm.compiler.java.BytecodeParser.processBlock(BytecodeParser.java:3204)
    at org.graalvm.compiler.java.BytecodeParser.build(BytecodeParser.java:1085)
    at org.graalvm.compiler.java.BytecodeParser.buildRootMethod(BytecodeParser.java:979)
    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:209)
    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.StaticInvokeTypeFlow.update(InvokeTypeFlow.java:346)
    at com.oracle.graal.pointsto.BigBang$2.run(BigBang.java:523)
    at com.oracle.graal.pointsto.util.CompletionExecutor.lambda$execute$0(CompletionExecutor.java:175)
    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)
Caused by: java.lang.ClassNotFoundException: org.eclipse.jetty.alpn.ALPN$Provider
    at java.net.URLClassLoader.findClass(URLClassLoader.java:382)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:419)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:352)
    ... 34 more

Expected behavior

Doing the same as above but based on the previous https://github.com/graalvm/openjdk8-jvmci-builder/releases/tag/jvmci-20.0-b02 release results in a successful build. The same should work when using a GraalVM release based on jvmci-20.0-b03.

Actual behavior

Building the Quarkus hello.world image when using a GraalVM release based on jvmci-20.0-b03 fails with the error message shown above.

To Reproduce
Steps to reproduce the behavior:

1. Get and extract https://github.com/graalvm/graal-jvmci-8/releases/download/jvmci-20.0-b03/openjdk-8u252-jvmci-20.0-b03-linux-amd64.tar.gz
2. Set JAVA_HOME to the openjdk-8u252-jvmci-20.0-b03 release
3. Clone https://github.com/oracle/graal/
4. Change to graal/vm & build a GraalVM with mx --dy /substratevm --disable-installables=true --force-bash-launchers=gu,native-image-configure,polyglot --skip-libraries=native-image-agent,polyglot
5. Clone https://github.com/olpaw/quarkus-hello-world and change to quarkus-hello-world
6. Build with GRAALVM_HOME=<path-to>/graal/vm/latest_graalvm_home mvn package -Pnative to see the error message decribed above.

Environment (please complete the following information):

• Output of uname -a or ver: Linux olpaw.lan 5.5.10-200.fc31.x86_64 #1 SMP Wed Mar 18 14:21:38 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
• Output of java -version:

openjdk version "1.8.0_252"
OpenJDK Runtime Environment (build 1.8.0_252-b05)
OpenJDK 64-Bit Server VM (build 25.252-b05-jvmci-20.0-b03, mixed mode)

• GraalVM version (if different from Java): see Steps to reproduce pt 4.
• Quarkus version or git rev: 1.2.0.Final
• Build tool (ie. output of mvnw --version or gradlew --version): Apache Maven 3.5.4 (Red Hat 3.5.4-5)

[geoand]

cc @galderz @dmlloyd

[geoand]

@olpaw Thanks for reporting.

Have you tried with Quarkus 1.3.0.Final by any chance?

[olpaw]

Have you tried with Quarkus 1.3.0.Final by any chance?

Hi @geoand using <quarkus.version>1.3.0.Final</quarkus.version> here https://github.com/olpaw/quarkus-hello-world/blob/3aa44d265760d7ba54d014110cbb95270fe0e345/pom.xml#L8 gives the same behaviour. So the reported issue is indifferent to the quarkus.version setting.

[geoand]

Thank you very much for checking @olpaw

[dmlloyd]

I'm assuming that this is due to some Netty update or change with the way we integrate with Netty, since we're not using Jetty. But Netty should be using the Java 11 ALPN interface at this point I would think. It might be related to enabling HTTP2?

[olpaw]

I compared the static analysis results of jvmci-20.0-b03 vs jvmci-20.0-b02 and found the following delta in the output of reports/call_tree_*.txt that I get when I add -Dquarkus.native.additional-build-args=-H:+PrintAnalysisCallTree:
With the working jvmci-20.0-b02 I see

└── is overridden by io.netty.handler.ssl.JdkSslContext.newEngine(io.netty.buffer.ByteBufAllocator):javax.net.ssl.SSLEngine id=26482
    ├── directly calls io.netty.handler.ssl.JdkSslContext.configureAndWrapEngine(javax.net.ssl.SSLEngine, io.netty.buffer.ByteBufAllocator):javax.net.ssl.SSLEngine id=28567 @bc
    │   ├── virtually calls io.netty.handler.ssl.JdkApplicationProtocolNegotiator$AllocatorAwareSslEngineWrapperFactory.wrapSslEngine(javax.net.ssl.SSLEngine, io.netty.buffer.B
    │   │   └── is overridden by io.netty.handler.ssl.JdkAlpnApplicationProtocolNegotiator$AlpnWrapper.wrapSslEngine(javax.net.ssl.SSLEngine, io.netty.buffer.ByteBufAllocator,
    │   │       └── directly calls io.netty.handler.ssl.Java9SslEngine.<init>(javax.net.ssl.SSLEngine, io.netty.handler.ssl.JdkApplicationProtocolNegotiator, boolean):void id=3

with the failing jvmci-20.0-b03 the subtree shows

└── is overridden by io.netty.handler.ssl.JdkSslContext.newEngine(io.netty.buffer.ByteBufAllocator):javax.net.ssl.SSLEngine id=23352
    ├── directly calls io.netty.handler.ssl.JdkSslContext.configureAndWrapEngine(javax.net.ssl.SSLEngine, io.netty.buffer.ByteBufAllocator):javax.net.ssl.SSLEngine id=25352 @bc
    │   ├── virtually calls io.netty.handler.ssl.JdkApplicationProtocolNegotiator$AllocatorAwareSslEngineWrapperFactory.wrapSslEngine(javax.net.ssl.SSLEngine, io.netty.buffer.B
    │   │   └── is overridden by io.netty.handler.ssl.JdkAlpnApplicationProtocolNegotiator$AlpnWrapper.wrapSslEngine(javax.net.ssl.SSLEngine, io.netty.buffer.ByteBufAllocator,
    │   │       ├── directly calls io.netty.handler.ssl.JettyAlpnSslEngine.isAvailable():boolean id=27708 @bci=3 
    │   │       ├── directly calls io.netty.handler.ssl.JettyAlpnSslEngine.newClientEngine(javax.net.ssl.SSLEngine, io.netty.handler.ssl.JdkApplicationProtocolNegotiator):io.ne
    │   │       ├── directly calls io.netty.handler.ssl.JettyAlpnSslEngine.newServerEngine(javax.net.ssl.SSLEngine, io.netty.handler.ssl.JdkApplicationProtocolNegotiator):io.ne
    │   │       ├── directly calls java.lang.Class.getName():java.lang.String id-ref=1155 @bci=54 
    │   │       ├── directly calls java.lang.RuntimeException.<init>(java.lang.String):void id-ref=675 @bci=63 
    │   │       ├── directly calls java.lang.StringBuilder.<init>():void id-ref=795 @bci=42 
    │   │       ├── directly calls java.lang.StringBuilder.append(java.lang.String):java.lang.StringBuilder id-ref=796 @bci=57 
    │   │       ├── directly calls java.lang.StringBuilder.append(java.lang.String):java.lang.StringBuilder id-ref=796 @bci=47 
    │   │       └── directly calls java.lang.StringBuilder.toString():java.lang.String id-ref=797 @bci=60 

I have trouble understanding how this makes sense. How can it be that in the case where we do not see the error we have io.netty.handler.ssl.Java9SslEngine.<init> in the call tree when all this is Java 8. Why would

static boolean jdkAlpnSupported() {
    return PlatformDependent.javaVersion() >= 9 && Java9SslUtils.supportsAlpn();
}

evaluate to true in https://github.com/netty/netty/blob/0c3eae34ec25203e22d3fa6a678a11a936f9c8b4/handler/src/main/java/io/netty/handler/ssl/JdkAlpnApplicationProtocolNegotiator.java#L138 ?

[jaikiran]

Hello @olpaw,

How can it be that in the case where we do not see the error we have io.netty.handler.ssl.Java9SslEngine. in the call tree when all this is Java 8

Can you share the complete Maven build logs of the run that uses jvmci-20.0-b02 against this Quarkus project? I'm especially interested in one line in that output which should look something like:

[INFO] [io.quarkus.deployment.pkg.steps.NativeImageBuildStep] Running Quarkus native-image plugin on GraalVM Version 20.1.0-dev (Java Version 1.8.0_242)

[jaikiran]

Keeping aside that call tree analysis (which I suspect might have to be some local setup issue - I couldn't generate that call tree with jvmci-20.0-b02 against my setup), I think the difference in behaviour between jvmci-20.0-b02 and jvmci-20.0-b03 comes down to the fact that jvmci-20.0-b03 uses JDK 1.8.0_252:

openjdk version "1.8.0_252"
OpenJDK Runtime Environment (build 1.8.0_252-b05)
OpenJDK 64-Bit Server VM (build 25.252-b05-jvmci-20.0-b03, mixed mode)

This JDK 8 252 upgrade version has now brought in ALPN extension as part of this backport[1] and that triggers Netty's JettyAlpnSslEngine#isAvailable[2] to return true since it can load the sun.security.ssl.ALPNExtension class[3]. That then cascades into Netty trying to create a client engine[4].

Of course, this is the cause of the issue. I haven't yet spent time to see how to fix this and get a clean build with this newer version.

[1] https://bugs.openjdk.java.net/browse/JDK-8239028
[2] https://github.com/netty/netty/blob/0c3eae34ec25203e22d3fa6a678a11a936f9c8b4/handler/src/main/java/io/netty/handler/ssl/JettyAlpnSslEngine.java#L36
[3] https://github.com/netty/netty/blob/0c3eae34ec25203e22d3fa6a678a11a936f9c8b4/handler/src/main/java/io/netty/handler/ssl/JettyAlpnSslEngine.java#L44
[4] https://github.com/netty/netty/blob/0c3eae34ec25203e22d3fa6a678a11a936f9c8b4/handler/src/main/java/io/netty/handler/ssl/JdkAlpnApplicationProtocolNegotiator.java#L142

[jaikiran]

Of course, this is the cause of the issue. I haven't yet spent time to see how to fix this and get a clean build with this newer version.

I had a bit more detailed look at this. Quarkus already has necessary substitutions in place to avoid pulling in these Jetty ALPN dependencies from Netty. Very specifically it has this[1]. That substitution has the following code:

if (Target_io_netty_handler_ssl_JettyAlpnSslEngine.isAvailable()) {

and the implementation of Target_io_netty_handler_ssl_JettyAlpnSslEngine.isAvailable() is available in that same file here[2]:

        @Alias
    static boolean isAvailable() {
        return false;
    }

For some reason, it looks like the code analysis engine in native-image code generator looks at the actual implementation of io.netty.handler.ssl.JettyAlpnSslEngine#isAvailable() method instead of this Target_io_netty_handler_ssl_JettyAlpnSslEngine.isAvailable(). Changing this @Alias to @Substitue gets it working. I've issued a PR for that here https://github.com/quarkusio/quarkus/pull/8176. However, I'm unsure why a direct call to Target_io_netty_handler_ssl_JettyAlpnSslEngine.isAvailable() from a class in the hosted VM, would bring in any @Alias or @Substitute semantics into picture. @olpaw, @dmlloyd, would you know?

[1] https://github.com/quarkusio/quarkus/blob/master/extensions/netty/runtime/src/main/java/io/quarkus/netty/runtime/graal/NettySubstitutions.java#L106
[2] https://github.com/quarkusio/quarkus/blob/master/extensions/netty/runtime/src/main/java/io/quarkus/netty/runtime/graal/NettySubstitutions.java#L125

[jaikiran]

However, I'm unsure why a direct call to Target_io_netty_handler_ssl_JettyAlpnSslEngine.isAvailable() from a class in the hosted VM, would bring in any @Alias or @Substitute semantics into picture. @olpaw, @dmlloyd, would you know?

After reading the documentation of @Alias https://github.com/oracle/graal/blob/master/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/annotate/Alias.java#L38, the umpteenth time, I think I finally understand what is does or is meant for. So it's actually a way to avoid compile time dependency (and Java compiler access checks) against the "target class" the @Alias is representing. During code analysis in native-image generation, the code analyzer will still look at the code in the "target class'" aliased method and generate the call tree. With that context, I think the PR I submitted is the right fix then (since we actually want to substitute the code in isAvailable to return false).

[olpaw]

@jaikiran Thanks a lot!

Yes, the use of @Alias is wrong if you want to substitute the implementation of JettyAlpnSslEngine#isAvailable(). For that you have to use

@Substitute
static boolean isAvailable() {
        return false;
}

@Alias on the other hand is used on methods if you want to make a method that is usually not accessible (e.g. because its private) available to you. For example, https://github.com/oracle/graal/blob/8d47699927f5e715f5b434944be9f43b2c810df3/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/Target_java_lang_Shutdown.java#L70 allows us to call shutdown() from https://github.com/oracle/graal/blob/8d47699927f5e715f5b434944be9f43b2c810df3/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/RuntimeSupport.java#L137 which would otherwise not be possible because it is package-private in java.lang.Shutdown#shutdown.

BTW, it looks like all uses of @Alias in the following range:
https://github.com/quarkusio/quarkus/blob/master/extensions/netty/runtime/src/main/java/io/quarkus/netty/runtime/graal/NettySubstitutions.java#L123-L141
should be replaced with @Substitute. cc @dmlloyd