Slf4j的MDC初尝试
为什么会用到MDC?
本人使用Java两年时间,鉴于经验有限,在开发java后端代码过程中,为了定位问题,希望同一个线程的requestId可以从web层的日志一直输出到dao层,这样使用Linux命令 grep 的时候,可以把同一个线程的相关日志都检索出来,一开始我是这样实现的:
在每次请求的时候,获取到请求的sessionId或者在web层生成一个sessionId,并将该sessionId透传到service层,dao层等,然后在每次log中将该log输出到日志中。
这个方案是完全可以实现上述功能的,但是代码侵入型强且代码冗余。为了实现从web端到底层的所有log输出同一个线程的sessionId,需要透传该id且显示打印到日志中。
于是我在思考,肯定是有更合适的方式解决此类问题,因此找到了MDC这个东东。
什么是MDC?
MDC(Mapped Diagnostic Context,映射调试上下文)是 log4j 和 logback 提供的一种方便在多线程条件下记录日志的功能。具体介绍参考 链接。
自己的理解,MDC相当于一个全局的哈希表,配合AOP/Filter/Interceptor这类工具,在每个请求到来时,将对应的sessionId put到MDC中,同时在log输出中增加 %X{对应的key},会自动将每个想成相关的日志增加上sessionId这个字段,很方便。
关于MDC的底层实现原理,可参考这篇博客。
使用Demo
下面以Interceptor为例,看下MDC的使用。
具体使用环境: spring boot工程
构造一个拦截器
package xxx; import java.util.UUID; import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpServletResponse; import org.slf4j.MDC; import org.springframework.web.servlet.handler.HandlerInterceptorAdapter; /*** * 日志拦截器的Demo * * @author xxx * @since 2018/12/06 */ public class LogInterceptor extends HandlerInterceptorAdapter { private final static String REQUEST_ID = "REQUEST_ID"; @Override public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception { // 删除requestId MDC.remove(REQUEST_ID); } @Override public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception { String requestId = UUID.randomUUID().toString().replace("-", "");
// 在拦截器中将对应的requestId放到MDC中 MDC.put(REQUEST_ID, requestId); return true; } }
添加拦截器
package xxx; import org.springframework.context.annotation.Bean; import org.springframework.context.annotation.ComponentScan; import org.springframework.context.annotation.Configuration; import org.springframework.web.servlet.HandlerInterceptor; import org.springframework.web.servlet.config.annotation.InterceptorRegistry; import org.springframework.web.servlet.config.annotation.WebMvcConfigurerAdapter; /** * 注册拦截器Demo * * @author xxx * @since 2018/12/06 */ @Configuration @ComponentScan(basePackageClasses={WebMvcConfigDemo.class}) public class WebMvcConfigDemo extends WebMvcConfigurerAdapter { /** 把相关的拦截器注入为Bean */ @Bean public HandlerInterceptor logInterceptor() { return new LogInterceptor(); } /** 添加拦截器 */ @Override public void addInterceptors(InterceptorRegistry registry) { registry.addInterceptor(logInterceptor()).addPathPatterns("/**"); super.addInterceptors(registry); } }
日志配置
<property name="CONSOLE_LOG_PATTERN" value="%red(%date{yyyy-MM-dd HH:mm:ss.SSS}) %X{REQUEST_ID} %green([%16.16thread]) %highlight(%-5level) %boldGreen(%-40.40logger{39}) - %msg%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"></property>
测试demo
web层代码
@GetMapping(value = "/getById") public Result getById(@RequestParam(name = "id") Long id) { logger.info("==========test log requestId in controller=============="); return dataplusAuthorityTenantService.testMDCInService(id); }
service层代码
@Override public Result testMDCInService(Long id) { logger.info("==========test log requestId in service=============="); return super.get(id); }
测试输出
[31m2018-12-06 19:49:45.298[0;39m ed4b3d86377140af8f8f3f138dfc0f78 [32m[-nio-7001-exec-1][0;39m [34mINFO [0;39m [1;32mc.a.DataplusAuthorityTenantApiController[0;39m - ==========test log requestId in controller============== [31m2018-12-06 19:49:45.316[0;39m ed4b3d86377140af8f8f3f138dfc0f78 [32m[-nio-7001-exec-1][0;39m [34mINFO [0;39m [1;32ms.d.i.DataplusAuthorityTenantServiceImpl[0;39m - ==========test log requestId in service==============
MDC带来的好处
1 应急
如果你的系统已经上线,突然日志中要增加一些额外信息,如果直接改代码,那你的代码都需要打补丁;如果直接扔在MDC中,直接配置在log中即可。
2 代码规范
在多线程环境中(现在几乎没有单线程),可直接通过拦截器/过滤器/AOP+log配置方式直接输出每个线程唯一的sessionId,不需要侵入到每行代码;
3 日志链路追踪
同2,尤其是喜欢在日志文件中使用grep命令的童鞋,一键grep;