系列文章目录
目录
系列文章目录
前言
一、MDC简介及常用API
简介
API
二、MDC使用
TraceInterceptor
修改logback日志格式
三、MDC的坑
前言
开发过程中难免遇到需要查看日志来找出问题出在哪一环节的情况,而在实际情况中服务之间互相调用所产生的日志冗长且复杂,若是再加上同一时间别的请求所产生的日志,想要精准定位自己想要查看的日志就比较麻烦。为解决此问题,遂使用MDC日志追踪。
一、MDC简介及常用API
简介
MDC(Mapped Diagnostic Context,映射调试上下文)是 log4j 和 logback 提供的一种方便在多线程条件下记录日志的功能。MDC 可以看成是一个与当前线程绑定的Map,可以往其中添加键值对。MDC 中包含的内容可以被同一线程中执行的代码所访问。当前线程的子线程会继承其父线程中的 MDC 的内容。当需要记录日志时,只需要从 MDC 中获取所需的信息即可。MDC 的内容则由程序在适当的时候保存进去。对于一个 Web 应用来说,通常是在请求被处理的最开始保存这些数据。
API
- clear() :移除所有MDC
MDC.clear();
- get (String key) :获取当前线程MDC中指定key的值
MDC.get("traceId");
- put(String key, Object o) :往当前线程的MDC中存入指定的键值对
MDC.put("traceId", IdUtil.simpleUUID());
- remove(String key) :删除当前线程MDC中指定的键值对
MDC.remove("traceId");
二、MDC使用
- 拦截器中使用MDC put 键值对。使得所有请求,从一开始就标记上特定标识。
- 如果是微服务之间的调用,则需要上层服务在header中添加标识同请求一起传输过来。下层服务直接使用上层服务的标识,就可以将日志串联起来。
TraceInterceptor
import cn.hutool.core.util.IdUtil;
import org.apache.commons.lang3.StringUtils;
import org.slf4j.MDC;
import org.springframework.web.servlet.HandlerInterceptor;
import org.springframework.web.servlet.ModelAndView;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
public class TraceInterceptor implements HandlerInterceptor {
/**
* 在业务处理器处理请求之前被调用。预处理,可以进行编码、安全控制、权限校验等处理
*/
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
String traceId = request.getHeader("requestId");
if (StringUtils.isBlank(traceId)) {
traceId = IdUtil.simpleUUID();
}
MDC.put("traceId", traceId);
return true;
}
/**
* 在业务处理器处理请求执行完成后,生成视图之前执行。后处理(调用了Service并返回ModelAndView,但未进行页面渲染),
* 有机会修改ModelAndView (这个博主就基本不怎么用了)
*/
@Override
public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception {
HandlerInterceptor.super.postHandle(request, response, handler, modelAndView);
}
/**
* 在DispatcherServlet完全处理完请求后被调用,可用于清理资源等。返回处理(已经渲染了页面)
*/
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
MDC.clear();
}
}
修改logback日志格式
<appender name="file-all" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${LOG_HOME}/file-all.log</file>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>${LOG_HOME}/file-all.log.%d{yyyy-MM-dd}</fileNamePattern>
</rollingPolicy>
<!-- <encoder>:对记录事件进行格式化。负责两件事,一是把日志信息转换成字节数组,二是把字节数组写入到输出流。-->
<!-- PatternLayoutEncoder 是唯一有用的且默认的encoder ,有一个<pattern>节点,用来设置日志的输入格式。使用“%”加“转换符”方式,如果要输出“%”,则必须用“\”对“\%”进行转义。-->
<encoder>
<pattern>[traceId:%X{traceId}]-[%d{yyyy-MM-dd HH:mm:ss:SSS}]-[%t]-[%p]-%m%n</pattern>
</encoder>
</appender>
最终效果
[traceId:a891644e7a844b57bf4a13c9ea40b128]-[2023-04-27 17:56:06:986]-[http-nio-7001-exec-2]-[INFO]-UserSignQueryHandler.param=UserSignQuery(type=1, userId=404278)
[traceId:a891644e7a844b57bf4a13c9ea40b128]-[2023-04-27 17:56:06:986]-[http-nio-7001-exec-2]-[INFO]-shushan.user.sign.service.getUserSign cost time 0ms
[traceId:]-[2023-04-27 17:56:13:229]-[http-nio-7001-exec-16]-[INFO]-CircleController.queryOwnerList#param=OwnerCirclePageQuery(ownerId=404278)
[traceId:c4a58ea747da4d64a4b1b4b344078a33]-[2023-04-27 17:56:13:229]-[http-nio-7001-exec-16]-[INFO]-OwnerCirclePageQueryHandler.param=OwnerCirclePageQuery(ownerId=404278)
[traceId:c4a58ea747da4d64a4b1b4b344078a33]-[2023-04-27 17:56:13:230]-[http-nio-7001-exec-16]-[DEBUG]-==> Preparing: SELECT COUNT(*) FROM circle WHERE (owner_id = ? AND del_flag = ?)
[traceId:c4a58ea747da4d64a4b1b4b344078a33]-[2023-04-27 17:56:13:230]-[http-nio-7001-exec-16]-[DEBUG]-==> Parameters: 404278(Long), 0(Integer)
[traceId:c4a58ea747da4d64a4b1b4b344078a33]-[2023-04-27 17:56:13:234]-[http-nio-7001-exec-16]-[DEBUG]-<== Total: 1
三、MDC的坑
主线程中,如果使用了线程池,会导致线程池中丢失MDC信息;
解决办法:需要我们自己重写线程池,在调用线程跳动run之前,获取到主线程的MDC信息,重新put到子线程中的。
public class MDCThreadPoolExecutor extends ThreadPoolExecutor {
public MDCThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, @NotNull TimeUnit unit, @NotNull BlockingQueue<Runnable> workQueue) {
super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
}
@Override
public void execute(Runnable command) {
super.execute(MDCThreadPoolExecutor.executeRunable(command, MDC.getCopyOfContextMap()));
}
@Override
public Future<?> submit(Runnable task) {
return super.submit(MDCThreadPoolExecutor.executeRunable(task, MDC.getCopyOfContextMap()));
}
@Override
public <T> Future<T> submit(Callable<T> callable) {
return super.submit(MDCThreadPoolExecutor.submitCallable(callable,MDC.getCopyOfContextMap()));
}
public static Runnable executeRunable(Runnable runnable ,Map<String,String> mdcContext){
return new Runnable() {
@Override
public void run() {
if (mdcContext == null) {
MDC.clear();
} else {
MDC.setContextMap(mdcContext);
}
try {
runnable.run();
} finally {
MDC.clear();
}
}
};
}
private static <T> Callable<T> submitCallable(Callable<T> callable, Map<String, String> context) {
return () -> {
if (context == null) {
MDC.clear();
} else {
MDC.setContextMap(context);
}
try {
return callable.call();
} finally {
MDC.clear();
}
};
}
}