events.action: opened
events.author: shakuzen
events.masked_author: username_0
events.text: 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)
  ```
events.title: Tomcat logs output twice
events.type: issue
events.action: created
events.author: wilkinsona
events.masked_author: username_1
events.text: Oh dear. Thanks for spotting this, @username_0.
events.type: comment
events.action: closed
events.author: wilkinsona
events.masked_author: username_1
events.type: issue
events.action: created
events.author: wilkinsona
events.masked_author: username_1
events.text: I've re-opened #8933 so that we can try to find a different fix.
events.type: comment