In order to help me diagnose failures of test (in particular when context fails to be initialized), I need to get a report such as the following to understand whether my @ConditionalOnProperty logic is correct.

@Configuration
@ConditionalOnProperty(value= DynamicCatalogConstants.OPT_IN_PROPERTY)
@EnableConfigurationProperties
public class DynamicCatalogServiceAutoConfiguration {
[...]

20-11-2020 14:47:02.380 [main] DEBUG o.s.b.a.l.ConditionEvaluationReportLoggingListener.logAutoConfigurationReport - 


============================
CONDITIONS EVALUATION REPORT
============================


Positive matches:
-----------------

   DynamicCatalogServiceAutoConfiguration matched:
      - @ConditionalOnProperty (osbcmdb.dynamic-catalog.enabled) matched (OnPropertyCondition)


Negative matches:
-----------------

    None


Exclusions:
-----------

    None


Unconditional classes:
----------------------

    None

I'm using spring-boot 2.3.6.

Observed behavior

The condition report is not invoked when context fails to start

Instead of a condition report, only the following context init exception is displayed

20-11-2020 14:24:10.609 [main] WARN  o.s.c.a.AnnotationConfigApplicationContext.refresh - Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.support.BeanDefinitionOverrideException: Invalid bean definition with name 'dynamicCatalogService' defined in com.orange.oss.osbcmdb.catalog.DynamicCatalogServiceAutoConfigurationTest$SingleServiceDefinitionAnswerAutoConfig: Cannot register bean definition [Root bean: class [null]; scope=; abstract=false; lazyInit=null; autowireMode=3; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=dynamicCatalogServiceAutoConfigurationTest.SingleServiceDefinitionAnswerAutoConfig; factoryMethodName=dynamicCatalogService; initMethodName=null; destroyMethodName=(inferred); defined in com.orange.oss.osbcmdb.catalog.DynamicCatalogServiceAutoConfigurationTest$SingleServiceDefinitionAnswerAutoConfig] for bean 'dynamicCatalogService': There is already [Root bean: class [null]; scope=; abstract=false; lazyInit=null; autowireMode=3; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=dynamicCatalogServiceAutoConfiguration; factoryMethodName=dynamicCatalogService; initMethodName=null; destroyMethodName=(inferred); defined in com.orange.oss.osbcmdb.catalog.DynamicCatalogServiceAutoConfiguration] bound.


java.lang.IllegalStateException: Unstarted application context org.springframework.boot.test.context.assertj.AssertableApplicationContext[startupFailure=org.springframework.beans.factory.support.BeanDefinitionOverrideException] failed to start

    at org.springframework.boot.test.context.assertj.AssertProviderApplicationContextInvocationHandler.getStartedApplicationContext(AssertProviderApplicationContextInvocationHandler.java:156)
    at org.springframework.boot.test.context.assertj.AssertProviderApplicationContextInvocationHandler.invokeApplicationContextMethod(AssertProviderApplicationContextInvocationHandler.java:147)
    at org.springframework.boot.test.context.assertj.AssertProviderApplicationContextInvocationHandler.invoke(AssertProviderApplicationContextInvocationHandler.java:85)
    at com.sun.proxy.$Proxy20.getBean(Unknown Source)
    at com.orange.oss.osbcmdb.catalog.DynamicCatalogServiceAutoConfigurationTest.lambda$dynamicServiceLoadWhenOptInProperty$2(DynamicCatalogServiceAutoConfigurationTest.java:84)

Sample code:

    @Test
    void dynamicServiceLoadWhenOptInProperty() {
        ConditionEvaluationReportLoggingListener initializer = new ConditionEvaluationReportLoggingListener(LogLevel.INFO);
        ApplicationContextRunner contextRunner = new ApplicationContextRunner()
            .withInitializer(initializer)
            .withConfiguration(AutoConfigurations.of(
                SingleServiceDefinitionAnswerAutoConfig.class,
                DynamicCatalogServiceAutoConfiguration.class,
                MockedMaintenanceInfoFormatterServiceConfig.class
            ))
            .withPropertyValues(DynamicCatalogConstants.OPT_IN_PROPERTY + "=true");
        contextRunner.run(context -> {
            Catalog catalog = context.getBean(Catalog.class);
            assertThat(catalog.getServiceDefinitions()).isNotEmpty();

            assertThat(context).hasSingleBean(Catalog.class);
        });
    }

What I tried

The logging level is properly set to debug.

Stepping into the debugger, it seems that the ConditionEvaluationReportLoggingListener is never invoked for event notifications.

I however managed to manually trigger the condition report printed by invoking it explicitly with the debugger:

References

  • https://docs.spring.io/spring-boot/docs/2.3.6.RELEASE/reference/htmlsingle/#boot-features-test-autoconfig
  • https://stackoverflow.com/questions/64930752/why-conditionevaluationreportlogginglistener-never-invoked-in-failed-context-tes

Comment From: snicoll

Thanks for the report. The doc does not indicate that if the test fails the report is not going to be printed, unfortunately. It would be nice if we could alleviate this limitation so that it is provided regardless of the outcome of the test.

Comment From: wilkinsona

I'm not sure that there's anything that we can do here. ConditionEvaluationReportLoggingListener listens for an ApplicationFailedEvent that is published by and is quite strongly coupled to SpringApplication. When using ApplicationContextRunner there's no SpringApplication involved – an application context is created and refresh directly instead – so I don't think we could create and publish an ApplicationFailedEvent as its SpringApplication (and args) would both have to be null.

Comment From: wilkinsona

We discussed this one today and decided that we don't want to do anything to make it work out of the box. Should it be needed, you can roll your own using existing public API. Something like this:

    @Test
    void deliberateStartupFailure() {
        ConditionEvaluationReportPrinter printer = new ConditionEvaluationReportPrinter();
        this.contextRunner.withInitializer(printer).withUserConfiguration(FailureConfig.class).run((context) -> {
            if (context.getStartupFailure() != null) {
                printer.print();
            }
        });
    }

    static class ConditionEvaluationReportPrinter
            implements ApplicationContextInitializer<ConfigurableApplicationContext> {

        private ConditionEvaluationReport report;

        @Override
        public void initialize(ConfigurableApplicationContext applicationContext) {
            this.report = ConditionEvaluationReport.get(applicationContext.getBeanFactory());
        }

        void print() {
            System.out.println(new ConditionEvaluationReportMessage(this.report));
        }

    }

    @Configuration(proxyBeanMethods = false)
    static class FailureConfig {

        @Bean
        public String failure() {
            throw new RuntimeException();
        }

    }

This could be reduced quite a bit by adding some public API to ConditionEvaluationReportLoggingListener to manually trigger logging of the report but, given that we haven't seen much demand for this, it doesn't feel worth it. We can reconsider in the future if demand becomes apparent.