Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
zakkak opened this issue Jul 23, 2024 · 3 comments · May be fixed by #42270 or #44619
Open

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

zakkak opened this issue Jul 23, 2024 · 3 comments · May be fixed by #42270 or #44619
Labels
area/native-image kind/bug Something isn't working

Comments

@zakkak
Copy link
Contributor

zakkak commented Jul 23, 2024

Describe the bug

$title

Relates to #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 [email protected]/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 [email protected]/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

e1e133f

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

applicationLogger.errorv(e, "Failed to start application");

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.

@zakkak zakkak added kind/bug Something isn't working area/native-image labels Jul 23, 2024
Copy link

quarkus-bot bot commented Jul 23, 2024

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

@geoand geoand changed the title Quarkus exists without showing thrown exception when using -H:ThrowMissingRegistrationErrors= Quarkus exits without showing thrown exception when using -H:ThrowMissingRegistrationErrors= Jul 24, 2024
zakkak added a commit to zakkak/quarkus that referenced this issue Aug 1, 2024
Prevent the usage of the logger when the application has not started
regardless of the cause since it's most likely not configured yet.

Closes quarkusio#42084
zakkak added a commit to zakkak/quarkus that referenced this issue Aug 1, 2024
Prevent the usage of the logger when the application has not started
regardless of the cause since it's most likely not configured yet.

Closes quarkusio#42084
zakkak added a commit to zakkak/quarkus that referenced this issue Aug 1, 2024
Prevent the usage of the logger when the application has not started
regardless of the cause since it's most likely not configured yet.

Closes quarkusio#42084
zakkak added a commit to zakkak/quarkus that referenced this issue Aug 1, 2024
Prevent the usage of the logger when the application has not started
regardless of the cause since it's most likely not configured yet.

Closes quarkusio#42084
@zakkak
Copy link
Contributor Author

zakkak commented Aug 27, 2024

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 [email protected]/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

LOG.error("Running a shutdown task failed", ex);

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 [email protected]/java.lang.ClassLoader.getResources(ClassLoader.java:99)
	at [email protected]/java.util.ServiceLoader$LazyClassPathLookupIterator.nextProviderClass(ServiceLoader.java:1203)
	at [email protected]/java.util.ServiceLoader$LazyClassPathLookupIterator.hasNextService(ServiceLoader.java:1228)
	at [email protected]/java.util.ServiceLoader$LazyClassPathLookupIterator.hasNext(ServiceLoader.java:1273)
	at [email protected]/java.util.ServiceLoader$2.hasNext(ServiceLoader.java:1309)
	at [email protected]/java.util.ServiceLoader$3.hasNext(ServiceLoader.java:1393)
	at [email protected]/java.util.ServiceLoader.findFirst(ServiceLoader.java:1812)
	at [email protected]/java.net.InetAddress.loadResolver(InetAddress.java:508)
	at [email protected]/java.net.InetAddress.resolver(InetAddress.java:488)
	at [email protected]/java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1826)
	at [email protected]/java.net.InetAddress$NameServiceAddresses.get(InetAddress.java:1139)
	at [email protected]/java.net.InetAddress.getAllByName0(InetAddress.java:1818)
	at [email protected]/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 [email protected]/java.security.AccessController.executePrivileged(AccessController.java:129)
	at [email protected]/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 [email protected]/java.lang.invoke.LambdaForm$DMH/sa346b79c.invokeStaticInit(LambdaForm$DMH)

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

@zakkak
Copy link
Contributor Author

zakkak commented Aug 27, 2024

I created #42810 to resolve the macOS issue but that requires graalvm/graalvm-community-jdk21u#9 being merged and released in the next Mandrel 23.1.x release to work.

With Mandrel 24.0.x (that includes #42810) and #42810 the issue is not reproducible on macOS

zakkak added a commit to zakkak/quarkus that referenced this issue Nov 21, 2024
zakkak added a commit to zakkak/quarkus that referenced this issue Nov 22, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/native-image kind/bug Something isn't working
Projects
None yet
1 participant