CODEWITHSUNDEEP
javaspringspring-bootspring-cloud
Dimitri Mestdagh
Dimitri Mestdagh

Reputation: 44675

Why does Spring boot execute SpringApplicationRunListener twice when using Eureka

I defined a simple SpringApplicationRunListener implementation with the following method:

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

When I run without any Spring cloud dependency I get the following log:

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

However, when I add the following dependency:

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

Then the "It's finished" line is logged twice, once at the end (like without Spring cloud/Eureka) and once at the start, even before the Spring boot logo appears:

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)

It also mentions the line "Started Application in ..." twice.

Is there a particular reason for this behaviour? I'm trying to write a SpringApplicationRunListener that relies on specific beans to have been created. However, if I add spring cloud, the first time it reaches the finished() method, the context is not yet created, so it currently throws an error.

Upvotes: 4

Views: 1319

Answers (1)

SkyWalker
SkyWalker

Reputation: 29150

Actually there is a issue of double calling for logging. By default Spring Boot sets up INFO level logging.

Previous version of spring boot before 1.3, as you are using 1.2.7 Then it uses

if you can't override spring boot's CONSOLE_LOG_PATTERN with your MDC value added, then it seems you have to live with every log message being written twice! (once with the spring boot console appender and once with your console appender with MDC added to the pattern)

But in spring boot 1.3 In newer versions of Spring Boot you can easily just include the base.xml from Spring Boot and create the following logback.xml.

<?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>

For more details, you can follow: How to disable logback ConsoleAppender in Spring Boot

Resource Link:

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

Upvotes: 2

Related Questions