opened
shakuzen
username_0
Generating a Spring Boot application with the web starter is enough to reproduce this.

With 2.0.0.M7, Tomcat logs are output once through the configured logger.
With current snapshots, they are output twice: once through the configured logger and once somehow else.

Maybe related to the changes made in #8933?

2.0.0.M7 log output:
```
  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::             (v2.0.0.M7)

2018-01-29 10:49:36.295  INFO 53599 --- [           main] com.example.demoact.DemoActApplication   : Starting DemoActApplication on **** with PID 53599 (*****)
2018-01-29 10:49:36.299  INFO 53599 --- [           main] com.example.demoact.DemoActApplication   : No active profile set, falling back to default profiles: default
2018-01-29 10:49:36.453  INFO 53599 --- [           main] ConfigServletWebServerApplicationContext : Refreshing org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@5119fb47: startup date [Mon Jan 29 10:49:36 JST 2018]; root of context hierarchy
2018-01-29 10:49:37.969  INFO 53599 --- [           main] o.h.v.i.engine.ValidatorFactoryImpl      : HV000238: Temporal validation tolerance set to 0.
2018-01-29 10:49:38.211  INFO 53599 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2018-01-29 10:49:38.221  INFO 53599 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2018-01-29 10:49:38.223  INFO 53599 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet Engine: Apache Tomcat/8.5.23
2018-01-29 10:49:38.232  INFO 53599 --- [ost-startStop-1] o.a.catalina.core.AprLifecycleListener   : The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: [/Users/thomas.ludwig/Library/Java/Extensions:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:.]
2018-01-29 10:49:38.308  INFO 53599 --- [ost-startStop-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2018-01-29 10:49:38.308  INFO 53599 --- [ost-startStop-1] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 1860 ms
2018-01-29 10:49:38.454  INFO 53599 --- [ost-startStop-1] o.s.b.w.servlet.ServletRegistrationBean  : Mapping servlet: 'dispatcherServlet' to [/]
2018-01-29 10:49:38.459  INFO 53599 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'characterEncodingFilter' to: [/*]
2018-01-29 10:49:38.460  INFO 53599 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'hiddenHttpMethodFilter' to: [/*]
2018-01-29 10:49:38.460  INFO 53599 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'httpPutFormContentFilter' to: [/*]
2018-01-29 10:49:38.460  INFO 53599 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'requestContextFilter' to: [/*]
2018-01-29 10:49:38.617  INFO 53599 --- [           main] o.h.v.i.engine.ValidatorFactoryImpl      : HV000238: Temporal validation tolerance set to 0.
2018-01-29 10:49:38.796  INFO 53599 --- [           main] s.w.s.m.m.a.RequestMappingHandlerAdapter : Looking for @ControllerAdvice: org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@5119fb47: startup date [Mon Jan 29 10:49:36 JST 2018]; root of context hierarchy
2018-01-29 10:49:38.850  INFO 53599 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error]}" onto public org.springframework.http.ResponseEntity<java.util.Map<java.lang.String, java.lang.Object>> org.springframework.boot.autoconfigure.web.servlet.error.BasicErrorController.error(javax.servlet.http.HttpServletRequest)
2018-01-29 10:49:38.851  INFO 53599 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error],produces=[text/html]}" onto public org.springframework.web.servlet.ModelAndView org.springframework.boot.autoconfigure.web.servlet.error.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)
2018-01-29 10:49:38.877  INFO 53599 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/webjars/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2018-01-29 10:49:38.878  INFO 53599 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2018-01-29 10:49:38.911  INFO 53599 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/**/favicon.ico] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2018-01-29 10:49:39.019  INFO 53599 --- [           main] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup
2018-01-29 10:49:39.082  INFO 53599 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2018-01-29 10:49:39.087  INFO 53599 --- [           main] com.example.demoact.DemoActApplication   : Started DemoActApplication in 3.412 seconds (JVM running for 5.268)
```

2.0.0.BUILD-SNAPSHOT
```
  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::  (v2.0.0.BUILD-SNAPSHOT)

2018-01-29 10:45:34.520  INFO 53234 --- [           main] com.example.demoact.DemoActApplication   : Starting DemoActApplication on **** with PID 53234 (*****)
2018-01-29 10:45:34.526  INFO 53234 --- [           main] com.example.demoact.DemoActApplication   : No active profile set, falling back to default profiles: default
2018-01-29 10:45:34.615  INFO 53234 --- [           main] ConfigServletWebServerApplicationContext : Refreshing org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@143640d5: startup date [Mon Jan 29 10:45:34 JST 2018]; root of context hierarchy
2018-01-29 10:45:36.316  INFO 53234 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
Jan 29, 2018 10:45:36 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service [Tomcat]
Jan 29, 2018 10:45:36 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/8.5.27
2018-01-29 10:45:36.328  INFO 53234 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2018-01-29 10:45:36.330  INFO 53234 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet Engine: Apache Tomcat/8.5.27
2018-01-29 10:45:36.340Jan 29, 2018 10:45:36 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
  INFO 53234 INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: [/Users/thomas.ludwig/Library/Java/Extensions:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:.]
--- [ost-startStop-1] o.a.catalina.core.AprLifecycleListener   : The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: [/Users/thomas.ludwig/Library/Java/Extensions:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:.]
2018-01-29 10:45:36.395  INFO 53234 --- [ost-startStop-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2018-01-29 10:45:36.395  INFO 53234 --- [ost-startStop-1] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 1786 ms
Jan 29, 2018 10:45:36 AM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring embedded WebApplicationContext
2018-01-29 10:45:36.517  INFO 53234 --- [ost-startStop-1] o.s.b.w.servlet.ServletRegistrationBean  : Servlet dispatcherServlet mapped to [/]
2018-01-29 10:45:36.521  INFO 53234 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'characterEncodingFilter' to: [/*]
2018-01-29 10:45:36.521  INFO 53234 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'hiddenHttpMethodFilter' to: [/*]
2018-01-29 10:45:36.521  INFO 53234 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'httpPutFormContentFilter' to: [/*]
2018-01-29 10:45:36.521  INFO 53234 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean   : Mapping filter: 'requestContextFilter' to: [/*]
2018-01-29 10:45:36.923  INFO 53234 --- [           main] s.w.s.m.m.a.RequestMappingHandlerAdapter : Looking for @ControllerAdvice: org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@143640d5: startup date [Mon Jan 29 10:45:34 JST 2018]; root of context hierarchy
2018-01-29 10:45:36.999  INFO 53234 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error]}" onto public org.springframework.http.ResponseEntity<java.util.Map<java.lang.String, java.lang.Object>> org.springframework.boot.autoconfigure.web.servlet.error.BasicErrorController.error(javax.servlet.http.HttpServletRequest)
2018-01-29 10:45:37.000  INFO 53234 --- [           main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error],produces=[text/html]}" onto public org.springframework.web.servlet.ModelAndView org.springframework.boot.autoconfigure.web.servlet.error.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)
2018-01-29 10:45:37.033  INFO 53234 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/webjars/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2018-01-29 10:45:37.033  INFO 53234 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2018-01-29 10:45:37.070  INFO 53234 --- [           main] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped URL path [/**/favicon.ico] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2018-01-29 10:45:37.250  INFO 53234 --- [           main] o.s.j.e.a.AnnotationMBeanExporter        : Registering beans for JMX exposure on startup
2018-01-29 10:45:37.318  INFO 53234 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2018-01-29 10:45:37.323  INFO 53234 --- [           main] com.example.demoact.DemoActApplication   : Started DemoActApplication in 3.438 seconds (JVM running for 4.893)
```
Tomcat logs output twice
issue
created
wilkinsona
username_1
Oh dear. Thanks for spotting this, @username_0.
comment
closed
wilkinsona
username_1
issue
created
wilkinsona
username_1
I've re-opened #8933 so that we can try to find a different fix.
comment