# learn-spring-boot-logging
**Repository Path**: lwx19960428/learn-spring-boot-logging
## Basic Information
- **Project Name**: learn-spring-boot-logging
- **Description**: SpringBoot同时集成logback和log4j的代码
- **Primary Language**: Java
- **License**: Not specified
- **Default Branch**: master
- **Homepage**: None
- **GVP Project**: No
## Statistics
- **Stars**: 1
- **Forks**: 0
- **Created**: 2019-03-29
- **Last Updated**: 2022-06-16
## Categories & Tags
**Categories**: Uncategorized
**Tags**: None
## README
# learn-spring-boot-logging
> 以下结论均依据SpringBoot 1.5.16.RELEASE版本得出
>
> 已知SpringBoot框架默认集成的是`org.springframework.boot:spring-boot-starter-logging`，而它向下又依赖slf4j和logback的相关jar包。
>
> 现有需求要使用log4j来进行日志的打印，需要明确知道日志打印到了何处，格式如何。
- 引入Maven依赖
```xml
org.springframework.boot
spring-boot-starter-web
log4j
log4j
1.2.17
```
- 编写测试类`Log4jController`和`Slf4jController`，暴露出来相关的url，供前端测试调用
- 编写`logback-spring.xml`配置文件，将日志同时打印到Console和File内。
- 启动程序，验证日志打印结果，log4j和slf4j的日志都可以在文件还有Console中打印
#### 控制台打印日志
```
2019-03-29 20:17:40.438 INFO 32068 --- [ main] cn.snowheart.boot.logging.Application : Starting Application on MacBookPro with PID 32068 (D:\workspace\personal\learn-spring-boot-logging\target\classes started by Lwx in D:\workspace\personal\learn-spring-boot-logging)
2019-03-29 20:17:40.442 INFO 32068 --- [ main] cn.snowheart.boot.logging.Application : No active profile set, falling back to default profiles: default
2019-03-29 20:17:40.497 INFO 32068 --- [ main] ationConfigEmbeddedWebApplicationContext : Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@35a3d49f: startup date [Fri Mar 29 20:17:40 CST 2019]; root of context hierarchy
2019-03-29 20:17:40.637 INFO 32068 --- [kground-preinit] o.h.validator.internal.util.Version : HV000001: Hibernate Validator 5.3.6.Final
2019-03-29 20:17:41.814 INFO 32068 --- [ main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat initialized with port(s): 8080 (http)
2019-03-29 20:17:41.835 INFO 32068 --- [ main] o.a.coyote.http11.Http11NioProtocol : Initializing ProtocolHandler ["http-nio-8080"]
2019-03-29 20:17:41.851 INFO 32068 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2019-03-29 20:17:41.851 INFO 32068 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet Engine: Apache Tomcat/8.5.34
2019-03-29 20:17:41.977 INFO 32068 --- [ost-startStop-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2019-03-29 20:17:41.977 INFO 32068 --- [ost-startStop-1] o.s.web.context.ContextLoader : Root WebApplicationContext: initialization completed in 1481 ms
2019-03-29 20:17:42.130 INFO 32068 --- [ost-startStop-1] o.s.b.w.servlet.ServletRegistrationBean : Mapping servlet: 'dispatcherServlet' to [/]
2019-03-29 20:17:42.134 INFO 32068 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'characterEncodingFilter' to: [/*]
2019-03-29 20:17:42.135 INFO 32068 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'hiddenHttpMethodFilter' to: [/*]
2019-03-29 20:17:42.135 INFO 32068 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'httpPutFormContentFilter' to: [/*]
2019-03-29 20:17:42.135 INFO 32068 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'requestContextFilter' to: [/*]
2019-03-29 20:17:42.506 INFO 32068 --- [ main] s.w.s.m.m.a.RequestMappingHandlerAdapter : Looking for @ControllerAdvice: org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@35a3d49f: startup date [Fri Mar 29 20:17:40 CST 2019]; root of context hierarchy
2019-03-29 20:17:42.564 INFO 32068 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/log4j/hello]}" onto public java.lang.String cn.snowheart.boot.logging.Log4jController.hello()
2019-03-29 20:17:42.564 INFO 32068 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/slf4j/hello]}" onto public java.lang.String cn.snowheart.boot.logging.Slf4jController.hello()
2019-03-29 20:17:42.567 INFO 32068 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error]}" onto public org.springframework.http.ResponseEntity> org.springframework.boot.autoconfigure.web.BasicErrorController.error(javax.servlet.http.HttpServletRequest)
2019-03-29 20:17:42.567 INFO 32068 --- [ 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.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)
2019-03-29 20:17:42.601 INFO 32068 --- [ main] o.s.w.s.handler.SimpleUrlHandlerMapping : Mapped URL path [/webjars/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2019-03-29 20:17:42.602 INFO 32068 --- [ main] o.s.w.s.handler.SimpleUrlHandlerMapping : Mapped URL path [/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2019-03-29 20:17:42.644 INFO 32068 --- [ main] o.s.w.s.handler.SimpleUrlHandlerMapping : Mapped URL path [/**/favicon.ico] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2019-03-29 20:17:42.870 INFO 32068 --- [ main] o.s.j.e.a.AnnotationMBeanExporter : Registering beans for JMX exposure on startup
2019-03-29 20:17:42.882 INFO 32068 --- [ main] o.a.coyote.http11.Http11NioProtocol : Starting ProtocolHandler ["http-nio-8080"]
2019-03-29 20:17:42.896 INFO 32068 --- [ main] o.a.tomcat.util.net.NioSelectorPool : Using a shared selector for servlet write/read
2019-03-29 20:17:42.911 INFO 32068 --- [ main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat started on port(s): 8080 (http)
2019-03-29 20:17:42.916 INFO 32068 --- [ main] cn.snowheart.boot.logging.Application : Started Application in 3.022 seconds (JVM running for 4.893)
2019-03-29 20:18:43.821 INFO 32068 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring FrameworkServlet 'dispatcherServlet'
2019-03-29 20:18:43.821 INFO 32068 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : FrameworkServlet 'dispatcherServlet': initialization started
2019-03-29 20:18:43.845 INFO 32068 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : FrameworkServlet 'dispatcherServlet': initialization completed in 24 ms
2019-03-29 20:18:43.889 INFO 32068 --- [nio-8080-exec-1] c.s.boot.logging.Log4jController : this is log4j version 1.x.x
2019-03-29 20:18:45.627 INFO 32068 --- [nio-8080-exec-3] c.s.boot.logging.Slf4jController : this is slf4j log...
```
#### 文件打印日志
```
2019-03-29 20:17:40.438 INFO 32068 --- [ main] cn.snowheart.boot.logging.Application : Starting Application on MacBookPro with PID 32068 (D:\workspace\personal\learn-spring-boot-logging\target\classes started by Lwx in D:\workspace\personal\learn-spring-boot-logging)
2019-03-29 20:17:40.442 INFO 32068 --- [ main] cn.snowheart.boot.logging.Application : No active profile set, falling back to default profiles: default
2019-03-29 20:17:40.497 INFO 32068 --- [ main] ationConfigEmbeddedWebApplicationContext : Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@35a3d49f: startup date [Fri Mar 29 20:17:40 CST 2019]; root of context hierarchy
2019-03-29 20:17:40.637 INFO 32068 --- [kground-preinit] o.h.validator.internal.util.Version : HV000001: Hibernate Validator 5.3.6.Final
2019-03-29 20:17:41.814 INFO 32068 --- [ main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat initialized with port(s): 8080 (http)
2019-03-29 20:17:41.835 INFO 32068 --- [ main] o.a.coyote.http11.Http11NioProtocol : Initializing ProtocolHandler ["http-nio-8080"]
2019-03-29 20:17:41.851 INFO 32068 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2019-03-29 20:17:41.851 INFO 32068 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet Engine: Apache Tomcat/8.5.34
2019-03-29 20:17:41.977 INFO 32068 --- [ost-startStop-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2019-03-29 20:17:41.977 INFO 32068 --- [ost-startStop-1] o.s.web.context.ContextLoader : Root WebApplicationContext: initialization completed in 1481 ms
2019-03-29 20:17:42.130 INFO 32068 --- [ost-startStop-1] o.s.b.w.servlet.ServletRegistrationBean : Mapping servlet: 'dispatcherServlet' to [/]
2019-03-29 20:17:42.134 INFO 32068 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'characterEncodingFilter' to: [/*]
2019-03-29 20:17:42.135 INFO 32068 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'hiddenHttpMethodFilter' to: [/*]
2019-03-29 20:17:42.135 INFO 32068 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'httpPutFormContentFilter' to: [/*]
2019-03-29 20:17:42.135 INFO 32068 --- [ost-startStop-1] o.s.b.w.servlet.FilterRegistrationBean : Mapping filter: 'requestContextFilter' to: [/*]
2019-03-29 20:17:42.506 INFO 32068 --- [ main] s.w.s.m.m.a.RequestMappingHandlerAdapter : Looking for @ControllerAdvice: org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@35a3d49f: startup date [Fri Mar 29 20:17:40 CST 2019]; root of context hierarchy
2019-03-29 20:17:42.564 INFO 32068 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/log4j/hello]}" onto public java.lang.String cn.snowheart.boot.logging.Log4jController.hello()
2019-03-29 20:17:42.564 INFO 32068 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/slf4j/hello]}" onto public java.lang.String cn.snowheart.boot.logging.Slf4jController.hello()
2019-03-29 20:17:42.567 INFO 32068 --- [ main] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped "{[/error]}" onto public org.springframework.http.ResponseEntity> org.springframework.boot.autoconfigure.web.BasicErrorController.error(javax.servlet.http.HttpServletRequest)
2019-03-29 20:17:42.567 INFO 32068 --- [ 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.BasicErrorController.errorHtml(javax.servlet.http.HttpServletRequest,javax.servlet.http.HttpServletResponse)
2019-03-29 20:17:42.601 INFO 32068 --- [ main] o.s.w.s.handler.SimpleUrlHandlerMapping : Mapped URL path [/webjars/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2019-03-29 20:17:42.602 INFO 32068 --- [ main] o.s.w.s.handler.SimpleUrlHandlerMapping : Mapped URL path [/**] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2019-03-29 20:17:42.644 INFO 32068 --- [ main] o.s.w.s.handler.SimpleUrlHandlerMapping : Mapped URL path [/**/favicon.ico] onto handler of type [class org.springframework.web.servlet.resource.ResourceHttpRequestHandler]
2019-03-29 20:17:42.870 INFO 32068 --- [ main] o.s.j.e.a.AnnotationMBeanExporter : Registering beans for JMX exposure on startup
2019-03-29 20:17:42.882 INFO 32068 --- [ main] o.a.coyote.http11.Http11NioProtocol : Starting ProtocolHandler ["http-nio-8080"]
2019-03-29 20:17:42.896 INFO 32068 --- [ main] o.a.tomcat.util.net.NioSelectorPool : Using a shared selector for servlet write/read
2019-03-29 20:17:42.911 INFO 32068 --- [ main] s.b.c.e.t.TomcatEmbeddedServletContainer : Tomcat started on port(s): 8080 (http)
2019-03-29 20:17:42.916 INFO 32068 --- [ main] cn.snowheart.boot.logging.Application : Started Application in 3.022 seconds (JVM running for 4.893)
2019-03-29 20:18:43.821 INFO 32068 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring FrameworkServlet 'dispatcherServlet'
2019-03-29 20:18:43.821 INFO 32068 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : FrameworkServlet 'dispatcherServlet': initialization started
2019-03-29 20:18:43.845 INFO 32068 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : FrameworkServlet 'dispatcherServlet': initialization completed in 24 ms
2019-03-29 20:18:43.889 INFO 32068 --- [nio-8080-exec-1] c.s.boot.logging.Log4jController : this is log4j version 1.x.x
2019-03-29 20:18:45.627 INFO 32068 --- [nio-8080-exec-3] c.s.boot.logging.Slf4jController : this is slf4j log...
```
---
### 结论
1. log4j-over-slf4j.jar与log4j.jar内的package名相同，根据类加载的双亲委托机制，加载到第一个`org.apache.log4j.Logger`后即不再向后加载。所以，当log4j的依赖在log4j-over-slf4j之前时，log4j的日志无法打印出来。
2. 程序使用中，最好一律使用slf4j提供的日志类。后续与其他程序集成或替换日志实现时，无需改造代码。
