FailureAnalyzers' unmet dependency errors add noise to logs

[chrisrhut]

Hi Spring Boot Team, happy new year 🎆

This happens on Spring Boot 2.4.1 and I confirmed it's still an issue on 2.4.2-SNAPSHOT.

If one executes a simple application with --debug output enabled and a forced initialization error:

@SpringBootApplication
class Application

fun main(args: Array<String>) {
    runApplication<Application>(*args)
}

@Component
class Runner : CommandLineRunner {
    override fun run(vararg args: String) {
        throw Error("Initialization failure")
    }
}

in IntelliJ IDEA, with the Spring Application defaults (notably, Enable launch optimization), the error output (with the Initialization failure stacktrace) is muddied by a lot of noise from FailureAnalyzer implementations whose dependencies aren't present in the classpath. For example:

2021-01-01 11:03:18.919 DEBUG 31074 --- [           main] o.s.boot.diagnostics.FailureAnalyzers    : FailureAnalyzer org.springframework.boot.autoconfigure.jdbc.HikariDriverConfigurationFailureAnalyzer@ff6077 failed

java.lang.NoClassDefFoundError: org/springframework/jdbc/CannotGetJdbcConnectionException
        at org.springframework.boot.autoconfigure.jdbc.HikariDriverConfigurationFailureAnalyzer.analyze(HikariDriverConfigurationFailureAnalyzer.java:29) ~[spring-boot-autoconfigure-2.4.1.jar:2.4.1]
        at org.springframework.boot.diagnostics.AbstractFailureAnalyzer.analyze(AbstractFailureAnalyzer.java:35) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.diagnostics.FailureAnalyzers.analyze(FailureAnalyzers.java:118) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.diagnostics.FailureAnalyzers.reportException(FailureAnalyzers.java:111) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.SpringApplication.reportFailure(SpringApplication.java:846) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.SpringApplication.handleRunFailure(SpringApplication.java:821) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:336) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1309) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1298) ~[spring-boot-2.4.1.jar:2.4.1]
        at example.ApplicationKt.main(Application.kt:22) ~[main/:na]
Caused by: java.lang.ClassNotFoundException: org.springframework.jdbc.CannotGetJdbcConnectionException
        at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:606) ~[na:na]
        at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:168) ~[na:na]
        at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:522) ~[na:na]
        ... 10 common frames omitted

2021-01-01 11:03:18.924 DEBUG 31074 --- [           main] o.s.boot.diagnostics.FailureAnalyzers    : FailureAnalyzer org.springframework.boot.liquibase.LiquibaseChangelogMissingFailureAnalyzer@37095ded failed

java.lang.NoClassDefFoundError: liquibase/exception/ChangeLogParseException
        at org.springframework.boot.liquibase.LiquibaseChangelogMissingFailureAnalyzer.analyze(LiquibaseChangelogMissingFailureAnalyzer.java:33) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.diagnostics.AbstractFailureAnalyzer.analyze(AbstractFailureAnalyzer.java:35) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.diagnostics.FailureAnalyzers.analyze(FailureAnalyzers.java:118) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.diagnostics.FailureAnalyzers.reportException(FailureAnalyzers.java:111) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.SpringApplication.reportFailure(SpringApplication.java:846) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.SpringApplication.handleRunFailure(SpringApplication.java:821) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:336) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1309) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1298) ~[spring-boot-2.4.1.jar:2.4.1]
        at example.ApplicationKt.main(Application.kt:22) ~[main/:na]
Caused by: java.lang.ClassNotFoundException: liquibase.exception.ChangeLogParseException
        at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:606) ~[na:na]
        at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:168) ~[na:na]
        at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:522) ~[na:na]
        ... 10 common frames omitted

2021-01-01 11:03:18.925 ERROR 31074 --- [           main] o.s.boot.SpringApplication               : Application run failed

java.lang.Error: Initialization failure
        at example.Runner.run(Application.kt:18) ~[main/:na]
        at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:804) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:788) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:333) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1309) ~[spring-boot-2.4.1.jar:2.4.1]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:1298) ~[spring-boot-2.4.1.jar:2.4.1]
        at example.Runner.run(Application.kt:18) ~[main/:na]

This does not occur if the application is run without the -noverify JVM flag which is enabled by the IJ "launch optimizations". The reflection-based FailureAnalyzer factories correctly skip over classes that cannot be instantiated. However, I wanted to report this issue because I think it's fair to say that developers will tend toward using the default run configuration, which implicitly enables this option. This results in needless extra cognitive load ("Liquibase?! But I'm not even using Liquibase!!") when trying to debug startup issues.

[chrisrhut]

An extremely naive fix is to simply "test drive" each FailureAnalyzer as it's created in FailureAnalyzers.java

	private FailureAnalyzer createAnalyzer(ConfigurableApplicationContext context, String className) throws Exception {
		Constructor<?> constructor = ClassUtils.forName(className, this.classLoader).getDeclaredConstructor();
		ReflectionUtils.makeAccessible(constructor);
		FailureAnalyzer analyzer = (FailureAnalyzer) constructor.newInstance();

		// Add this:
		analyzer.analyze(new Throwable());

		if (analyzer instanceof BeanFactoryAware || analyzer instanceof EnvironmentAware) {

Given the hack-ish nature of this change and the fact that it's also difficult to unit test this failure mode (since it basically requires a runtime linkage error), I'm hesitant to submit a PR, but would be happy to do so if it helps.

[wilkinsona]

I wonder if we should log the failures at trace level rather than debug?