为什么Spring boot在使用Eureka时执行SpringApplicationRunListener两次

Question

我使用以下方法定义了一个简单的SpringApplicationRunListener实现：

@Override
public void finished(ConfigurableApplicationContext configurableApplicationContext, Throwable throwable) {
    logger.info("It's finished");
}

当我在没有任何Spring cloud依赖项的情况下运行时，我会得到以下日志：

2016-04-27 10:37:37.702  INFO 5720 --- [           main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat started on port(s): 8080 (http)
2016-04-27 10:37:37.703  INFO 5720 --- [           main] b.a.test.LazyFilterRuntimeListener       : It's finished

<dependency>
    <groupId>org.springframework.cloud</groupId>
    <artifactId>spring-cloud-starter-eureka</artifactId>
</dependency>

2016-04-27 10:37:35.500  INFO 5720 --- [           main] s.c.a.AnnotationConfigApplicationContext : Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@255b53dc: startup date [Wed Apr 27 10:37:35 CEST 2016]; root of context hierarchy
2016-04-27 10:37:35.638  INFO 5720 --- [           main] f.a.AutowiredAnnotationBeanPostProcessor : JSR-330 'javax.inject.Inject' annotation found and supported for autowiring
2016-04-27 10:37:35.785  INFO 5720 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'encrypt.CONFIGURATION_PROPERTIES' of type [class org.springframework.cloud.bootstrap.encrypt.KeyProperties] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2016-04-27 10:37:35.786  INFO 5720 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'encryptionBootstrapConfiguration' of type [class org.springframework.cloud.bootstrap.encrypt.EncryptionBootstrapConfiguration$$EnhancerBySpringCGLIB$$268d5fc8] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2016-04-27 10:37:35.839  INFO 5720 --- [           main] b.c.test.LazyFilterRuntimeListener       : It's finished
2016-04-27 10:37:35.842  INFO 5720 --- [           main] be.company.test.TestApplication   : Started TestApplication in 0.499 seconds (JVM running for 0.86)

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v1.2.7.RELEASE)


...

2016-04-27 10:37:37.702  INFO 5720 --- [           main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat started on port(s): 8080 (http)
2016-04-27 10:37:37.703  INFO 5720 --- [           main] b.c.test.LazyFilterRuntimeListener       : It's finished
2016-04-27 10:37:37.703  INFO 5720 --- [           main] be.company.test.TestApplication   : Started TestApplication in 2.423 seconds (JVM running for 2.721)

它还两次提到“在...开始应用程序”这句话。

这种行为有什么特别的原因吗？我正在尝试编写一个SpringApplicationRunListener，它依赖于已经创建的特定bean。但是，如果我添加spring cloud，当它第一次到达finished()方法时，上下文尚未创建，因此当前抛出一个错误。

Answer 1

实际上，有一个双重调用日志记录的问题。默认情况下，Spring Boot设置信息级日志记录。

1.3之前的spring boot的早期版本，因为您正在使用1.2.7然后它使用

如果您不能通过添加MDC值来覆盖spring Boot的CONSOLE_LOG_PATTERN,那么您似乎必须对每个日志消息进行两次写入！（一次使用spring boot console appender，一次使用您的console appender并将MDC添加到模式中）

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/base.xml" />

    <root level="INFO">
        <appender-ref ref="FILE" />
    </root>
</configuration>

1. https://github.com/spring-projects/spring-boot/issues/1788
2. https://github.com/spring-projects/spring-boot/issues/2558