search

quarkusio / quarkus

Quarkus: Supersonic Subatomic Java.
https://quarkus.io
Apache License 2.0
13.87k stars 2.71k forks source link

Quarkus exits without showing thrown exception when using `-H:ThrowMissingRegistrationErrors=` #42084

Open zakkak opened 4 months ago

zakkak commented 4 months ago

Describe the bug

$title

Relates to https://github.com/quarkusio/quarkus/issues/41995

Expected behavior

When a MissingRegistrationError exception is thrown it should be shown on the console output (or logs), e.g. something like:

com.oracle.svm.core.jdk.resources.MissingResourceRegistrationError: The program tried to access the resource at path application.properties without it being registered as reachable. Add it to the resource metadata to solve this problem. See https://www.graalvm.org/latest/reference-manual/native-image/metadata/#resources-and-resource-bundles for help
    at org.graalvm.nativeimage.builder/com.oracle.svm.core.jdk.resources.MissingResourceRegistrationUtils.missingResource(MissingResourceRegistrationUtils.java:41)
    at org.graalvm.nativeimage.builder/com.oracle.svm.core.jdk.Resources.createURLs(Resources.java:460)
    at org.graalvm.nativeimage.builder/com.oracle.svm.core.jdk.Resources.createURLs(Resources.java:428)
    at org.graalvm.nativeimage.builder/com.oracle.svm.core.jdk.ResourcesHelper.nameToResourceListURLs(ResourcesHelper.java:115)
    at org.graalvm.nativeimage.builder/com.oracle.svm.core.jdk.ResourcesHelper.nameToResourceEnumerationURLs(ResourcesHelper.java:124)
    at java.base@21.0.4/java.lang.ClassLoader.getResources(ClassLoader.java:99)
    at io.smallrye.common.classloader.ClassPathUtils.consumeAsPaths(ClassPathUtils.java:84)
    at io.smallrye.config.AbstractLocationConfigSourceLoader.tryClassPath(AbstractLocationConfigSourceLoader.java:141)
    at io.smallrye.config.AbstractLocationConfigSourceLoader.loadConfigSources(AbstractLocationConfigSourceLoader.java:104)
    at io.smallrye.config.AbstractLocationConfigSourceLoader.loadConfigSources(AbstractLocationConfigSourceLoader.java:87)
    at io.smallrye.config.PropertiesConfigSourceLoader$InClassPath.getConfigSources(PropertiesConfigSourceLoader.java:47)
    at io.smallrye.config.PropertiesConfigSourceLoader.inClassPath(PropertiesConfigSourceLoader.java:33)
    at io.smallrye.config.SmallRyeConfigBuilder.getPropertiesSources(SmallRyeConfigBuilder.java:217)
    at io.smallrye.config.SmallRyeConfigBuilder.getDefaultSources(SmallRyeConfigBuilder.java:200)
    at io.smallrye.config.SmallRyeConfig$ConfigSources.buildSources(SmallRyeConfig.java:841)
    at io.smallrye.config.SmallRyeConfig$ConfigSources.<init>(SmallRyeConfig.java:770)
    at io.smallrye.config.SmallRyeConfig.<init>(SmallRyeConfig.java:85)
    at io.smallrye.config.SmallRyeConfigBuilder.build(SmallRyeConfigBuilder.java:736)
    at io.quarkus.runtime.generated.Config.readConfig(Unknown Source)
    at io.quarkus.runtime.generated.Config.createRunTimeConfig(Unknown Source)
    at io.quarkus.deployment.steps.RuntimeConfigSetup.deploy(Unknown Source)
    at io.quarkus.runner.ApplicationImpl.doStart(Unknown Source)
    at io.quarkus.runtime.Application.start(Application.java:101)
    at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:111)
    at io.quarkus.runtime.Quarkus.run(Quarkus.java:71)
    at io.quarkus.runtime.Quarkus.run(Quarkus.java:44)
    at io.quarkus.runner.GeneratedMain.main(Unknown Source)
    at java.base@21.0.4/java.lang.invoke.LambdaForm$DMH/sa346b79c.invokeStaticInit(LambdaForm$DMH)

Actual behavior

The native executable exits without printing anything.

How to Reproduce?

./mvnw -Dnative -pl integration-tests/picocli-native -Dnative.surefire.skip -Dformat.skip -Dno-descriptor-tests clean verify -Dquarkus.native.additional-build-args=-H:ThrowMissingRegistrationErrors=
./integration-tests/picocli-native/target/quarkus-integration-test-picocli-native-999-SNAPSHOT-runner -h

Output of uname -a or ver

Fedora 40

Output of java -version

21.0.4+7

Mandrel or GraalVM version (if different from Java)

Mandrel-23.1.4.0-Final

Quarkus version or git rev

e1e133fa419fbf2338f2b55eb49d69bb5eae3622

Build tool (ie. output of mvnw --version or gradlew --version)

Apache Maven 3.9.8 (36645f6c9b5079805ea5009217e36f2cffd34256)

Additional information

It looks like this is related to how Quarkus handles exceptions in https://github.com/quarkusio/quarkus/blob/e1987aa21da30b292e85bb5432fdaf6609ae4f9f/core/runtime/src/main/java/io/quarkus/runtime/ApplicationLifecycleManager.java#L197

The exception is thrown too early and Quarkus has not yet set up logging. The exception however is not ConfigurationException or ConfigValidationException so it's not handled specially and results in the observed behavior.

I believe there should be a way to check if the configuration is completed (or at least if logging is properly setup) regardless of the exception type so that Quarkus could still show exceptions, not matching the ones above, thrown during the configuration stage.

quarkus-bot[bot] commented 4 months ago

/cc @Karm (mandrel), @galderz (mandrel)

zakkak commented 3 months ago

Note that on MacOS the reproducer doesn't work exactly the same as the application fails due to an NCDFE

Exception in thread "main" java.lang.NoClassDefFoundError: Could not initialize class io.smallrye.common.net.HostName
    at org.jboss.logmanager.ExtLogRecord.<init>(ExtLogRecord.java:109)
    at org.jboss.logmanager.Logger.log(Logger.java:1046)
    at org.jboss.logmanager.Logger.log(Logger.java:1064)
    at org.jboss.logging.JBossLogManagerLogger.doLog(JBossLogManagerLogger.java:43)
    at org.jboss.logging.Logger.error(Logger.java:1509)
    at io.quarkus.runtime.StartupContext.runAllAndClear(StartupContext.java:81)
    at io.quarkus.runtime.StartupContext.close(StartupContext.java:70)
    at io.quarkus.runner.ApplicationImpl.doStart(Unknown Source)
    at io.quarkus.runtime.Application.start(Application.java:101)
    at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:119)
    at io.quarkus.runtime.Quarkus.run(Quarkus.java:71)
    at io.quarkus.runtime.Quarkus.run(Quarkus.java:44)
    at io.quarkus.runner.GeneratedMain.main(Unknown Source)
    at java.base@21.0.2/java.lang.invoke.LambdaForm$DMH/sa346b79c.invokeStaticInit(LambdaForm$DMH)

Inspecting the above stack trace I see that the NCDFE is thrown when trying to log an error triggered in

https://github.com/quarkusio/quarkus/blob/7a385dff3afed19ae74f1f7e51dc36b74ac00481/core/runtime/src/main/java/io/quarkus/runtime/StartupContext.java#L81

patching the code to print the stacktrace on stderr before trying to log the error shows the following stacktrace:

com.oracle.svm.core.jdk.resources.MissingResourceRegistrationError: The program tried to access the resource at path META-INF/services/java.net.spi.InetAddressResolverProvider without it being registered as reachable. Add it to the resource metadata to solve this problem. See https://www.graalvm.org/latest/reference-manual/native-image/metadata/#resources-and-resource-bundles for help
    at org.graalvm.nativeimage.builder/com.oracle.svm.core.jdk.resources.MissingResourceRegistrationUtils.missingResource(MissingResourceRegistrationUtils.java:41)
    at org.graalvm.nativeimage.builder/com.oracle.svm.core.jdk.Resources.createURLs(Resources.java:460)
    at org.graalvm.nativeimage.builder/com.oracle.svm.core.jdk.Resources.createURLs(Resources.java:428)
    at org.graalvm.nativeimage.builder/com.oracle.svm.core.jdk.ResourcesHelper.nameToResourceListURLs(ResourcesHelper.java:115)
    at org.graalvm.nativeimage.builder/com.oracle.svm.core.jdk.ResourcesHelper.nameToResourceEnumerationURLs(ResourcesHelper.java:124)
    at java.base@21.0.2/java.lang.ClassLoader.getResources(ClassLoader.java:99)
    at java.base@21.0.2/java.util.ServiceLoader$LazyClassPathLookupIterator.nextProviderClass(ServiceLoader.java:1203)
    at java.base@21.0.2/java.util.ServiceLoader$LazyClassPathLookupIterator.hasNextService(ServiceLoader.java:1228)
    at java.base@21.0.2/java.util.ServiceLoader$LazyClassPathLookupIterator.hasNext(ServiceLoader.java:1273)
    at java.base@21.0.2/java.util.ServiceLoader$2.hasNext(ServiceLoader.java:1309)
    at java.base@21.0.2/java.util.ServiceLoader$3.hasNext(ServiceLoader.java:1393)
    at java.base@21.0.2/java.util.ServiceLoader.findFirst(ServiceLoader.java:1812)
    at java.base@21.0.2/java.net.InetAddress.loadResolver(InetAddress.java:508)
    at java.base@21.0.2/java.net.InetAddress.resolver(InetAddress.java:488)
    at java.base@21.0.2/java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1826)
    at java.base@21.0.2/java.net.InetAddress$NameServiceAddresses.get(InetAddress.java:1139)
    at java.base@21.0.2/java.net.InetAddress.getAllByName0(InetAddress.java:1818)
    at java.base@21.0.2/java.net.InetAddress.getLocalHost(InetAddress.java:1931)
    at io.smallrye.common.net.HostName.getLocalHost(HostName.java:34)
    at io.smallrye.common.net.GetHostInfoAction.run(GetHostInfoAction.java:55)
    at io.smallrye.common.net.GetHostInfoAction.run(GetHostInfoAction.java:7)
    at java.base@21.0.2/java.security.AccessController.executePrivileged(AccessController.java:129)
    at java.base@21.0.2/java.security.AccessController.doPrivileged(AccessController.java:319)
    at io.smallrye.common.net.HostName.<clinit>(HostName.java:22)
    at org.jboss.logmanager.ExtLogRecord.<init>(ExtLogRecord.java:109)
    at org.jboss.logmanager.Logger.log(Logger.java:1046)
    at org.jboss.logging.JBossLogManagerLogger.doLogf(JBossLogManagerLogger.java:56)
    at org.jboss.logging.Logger.debugf(Logger.java:703)
    at io.quarkus.arc.impl.ArcContainerImpl.shutdown(ArcContainerImpl.java:473)
    at io.quarkus.arc.Arc.shutdown(Arc.java:65)
    at io.quarkus.arc.runtime.ArcRecorder$1.run(ArcRecorder.java:53)
    at io.quarkus.runtime.StartupContext.runAllAndClear(StartupContext.java:79)
    at io.quarkus.runtime.StartupContext.close(StartupContext.java:70)
    at io.quarkus.runner.ApplicationImpl.doStart(Unknown Source)
    at io.quarkus.runtime.Application.start(Application.java:101)
    at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:119)
    at io.quarkus.runtime.Quarkus.run(Quarkus.java:71)
    at io.quarkus.runtime.Quarkus.run(Quarkus.java:44)
    at io.quarkus.runner.GeneratedMain.main(Unknown Source)
    at java.base@21.0.2/java.lang.invoke.LambdaForm$DMH/sa346b79c.invokeStaticInit(LambdaForm$DMH)

not sure why this is not triggered on Linux...

zakkak commented 3 months ago

I created https://github.com/quarkusio/quarkus/pull/42810 to resolve the macOS issue but that requires https://github.com/graalvm/graalvm-community-jdk21u/pull/9 being merged and released in the next Mandrel 23.1.x release to work.

With Mandrel 24.0.x (that includes https://github.com/quarkusio/quarkus/pull/42810) and https://github.com/quarkusio/quarkus/pull/42810 the issue is not reproducible on macOS

zakkak commented 4 days ago

Interestingly, this is no longer reproducible with the latest dev builds of GraalVM for JDK 24.