Native image fails silently when a config import cannot be resolved

[wilkinsona]

Running on the JVM produces a failure:

$ java -jar build/libs/native-image-deferred-logging-0.0.1-SNAPSHOT.jar --spring.config.import=does-not-exist
14:08:17.134 [main] ERROR org.springframework.boot.SpringApplication -- Application run failed
java.lang.IllegalStateException: Unable to load config data from 'does-not-exist'
	at org.springframework.boot.context.config.StandardConfigDataLocationResolver.getReferences(StandardConfigDataLocationResolver.java:143)
	at org.springframework.boot.context.config.StandardConfigDataLocationResolver.getReferences(StandardConfigDataLocationResolver.java:128)
	at org.springframework.boot.context.config.StandardConfigDataLocationResolver.resolve(StandardConfigDataLocationResolver.java:121)
	at org.springframework.boot.context.config.ConfigDataLocationResolvers.lambda$resolve$1(ConfigDataLocationResolvers.java:102)
	at org.springframework.boot.context.config.ConfigDataLocationResolvers.resolve(ConfigDataLocationResolvers.java:113)
	at org.springframework.boot.context.config.ConfigDataLocationResolvers.resolve(ConfigDataLocationResolvers.java:102)
	at org.springframework.boot.context.config.ConfigDataLocationResolvers.resolve(ConfigDataLocationResolvers.java:94)
	at org.springframework.boot.context.config.ConfigDataImporter.resolve(ConfigDataImporter.java:106)
	at org.springframework.boot.context.config.ConfigDataImporter.resolve(ConfigDataImporter.java:98)
	at org.springframework.boot.context.config.ConfigDataImporter.resolveAndLoad(ConfigDataImporter.java:86)
	at org.springframework.boot.context.config.ConfigDataEnvironmentContributors.withProcessedImports(ConfigDataEnvironmentContributors.java:115)
	at org.springframework.boot.context.config.ConfigDataEnvironment.processInitial(ConfigDataEnvironment.java:242)
	at org.springframework.boot.context.config.ConfigDataEnvironment.processAndApply(ConfigDataEnvironment.java:229)
	at org.springframework.boot.context.config.ConfigDataEnvironmentPostProcessor.postProcessEnvironment(ConfigDataEnvironmentPostProcessor.java:96)
	at org.springframework.boot.context.config.ConfigDataEnvironmentPostProcessor.postProcessEnvironment(ConfigDataEnvironmentPostProcessor.java:89)
	at org.springframework.boot.env.EnvironmentPostProcessorApplicationListener.onApplicationEnvironmentPreparedEvent(EnvironmentPostProcessorApplicationListener.java:109)
	at org.springframework.boot.env.EnvironmentPostProcessorApplicationListener.onApplicationEvent(EnvironmentPostProcessorApplicationListener.java:94)
	at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:185)
	at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:178)
	at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:156)
	at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:138)
	at org.springframework.boot.context.event.EventPublishingRunListener.multicastInitialEvent(EventPublishingRunListener.java:136)
	at org.springframework.boot.context.event.EventPublishingRunListener.environmentPrepared(EventPublishingRunListener.java:81)
	at org.springframework.boot.SpringApplicationRunListeners.lambda$environmentPrepared$2(SpringApplicationRunListeners.java:64)
	at java.base/java.lang.Iterable.forEach(Iterable.java:75)
	at org.springframework.boot.SpringApplicationRunListeners.doWithListeners(SpringApplicationRunListeners.java:118)
	at org.springframework.boot.SpringApplicationRunListeners.doWithListeners(SpringApplicationRunListeners.java:112)
	at org.springframework.boot.SpringApplicationRunListeners.environmentPrepared(SpringApplicationRunListeners.java:63)
	at org.springframework.boot.SpringApplication.prepareEnvironment(SpringApplication.java:369)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:329)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1354)
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1343)
	at com.example.NativeImageDeferredLoggingApplication.main(NativeImageDeferredLoggingApplication.java:10)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
	at org.springframework.boot.loader.launch.Launcher.launch(Launcher.java:91)
	at org.springframework.boot.loader.launch.Launcher.launch(Launcher.java:53)
	at org.springframework.boot.loader.launch.JarLauncher.main(JarLauncher.java:58)
Caused by: java.lang.IllegalStateException: File extension is not known to any PropertySourceLoader. If the location is meant to reference a directory, it must end in '/' or File.separator
	at org.springframework.boot.context.config.StandardConfigDataLocationResolver.getReferencesForFile(StandardConfigDataLocationResolver.java:234)
	at org.springframework.boot.context.config.StandardConfigDataLocationResolver.getReferences(StandardConfigDataLocationResolver.java:140)
	... 37 common frames omitted
$

Running a native image of the same application fails silently:

$ ./build/native/nativeCompile/native-image-deferred-logging --spring.config.import=not-here
$

[wilkinsona]

My suspicion when discussing this will @OlgaMaciaszek and @sdeleuze was that this would be due to our deferred logging but that doesn't appear to be the case.

As far as I can tell, the problem is that the failure is occurring before we've had a chance to initialize Logback and Logback in its default configuration doesn't work in a native image. This means that this error logging is silent:

spring-boot/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/SpringApplication.java

Line 851 in 0bc5e27

logger.error("Application run failed", failure);

Via some primitive debugging (adding System.out calls to a copy of SpringApplication) I've confirmed that this is an instance of org.apache.commons.logging.LogAdapter$Slf4jLocationAwareLog as we would expect and that error logging is enabled.

Further primitive debugging has shown that the problem is that Logback has no appenders configured. Things are in this state as Logback cannot load its various built-in configurator classes:

• ch.qos.logback.classic.joran.SerializedModelConfigurator
• ch.qos.logback.classic.util.DefaultJoranConfigurator
• ch.qos.logback.classic.BasicConfigurator

When running on the JVM, BasicConfigurator creates a ConsoleAppender to which the error is logged. In a native image, BasicConfigurator cannot be loaded so Logback's left without any appenders and the event is silently dropped.

[wilkinsona]

None of the three configurator classes could be loaded because NBT 0.9.8 uses a version of the Logback reachability metadata that does not allow them to be loaded reflectively. NBT 0.10.1 fixes this for two of the three configurators by using a more up-to-date version of the metadata by default. The metadata is missing reflection configuration for ch.qos.logback.classic.BasicConfigurator so it doesn't completely address the problem. This will have to be fixed in the reachability metadata and oracle/graalvm-reachability-metadata#454 is tracking that.

In the meantime, the problem can be worked around by using NBT 0.10.1 and an additional runtime hint:

package com.example;

import org.springframework.aot.hint.MemberCategory;
import org.springframework.aot.hint.RuntimeHints;
import org.springframework.aot.hint.RuntimeHintsRegistrar;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.context.annotation.ImportRuntimeHints;

import com.example.NativeImageLoggingApplication.AdditionalLogbackHints;

import ch.qos.logback.classic.BasicConfigurator;

@SpringBootApplication
@ImportRuntimeHints(AdditionalLogbackHints.class)
public class NativeImageLoggingApplication {

	public static void main(String[] args) {
		SpringApplication.run(NativeImageLoggingApplication.class, args);
	}
	
	static class AdditionalLogbackHints implements RuntimeHintsRegistrar {

		@Override
		public void registerHints(RuntimeHints hints, ClassLoader classLoader) {
			hints.reflection().registerType(BasicConfigurator.class, MemberCategory.INVOKE_PUBLIC_CONSTRUCTORS);
		}
		
	}

}