上文介绍了SpringBoot集成LogBack的例子，文章末尾提到了如何区分每次请求的日志？本文介绍一下如何通过LogBack的MDC(Mapped Diagnostic Context)实现轻量级的链路追踪，直接上干货。
在日志上下文MDC创建请求ID
1、先写个工具类生成ID
public class TraceIdUtil {
// 注意这里是变量
public static final String TRACE_ID = "reqId";
//获取ID
public static String getTraceId() {
String traceId = (String) MDC.get(TRACE_ID);
return traceId == null ? "" : traceId;
}
//设置ID
public static void setTraceId(String traceId) {
MDC.put(TRACE_ID, traceId);
}
//移除ID
public static void remove() {
MDC.remove(TRACE_ID);
}
//生成ID,先随意生成一个uuid,这里可以用应用，IP,时间等生成，可以记录更多信息
public static String generateTraceId() {
return UUID.randomUUID().toString().replace("-", "");
}
}2、实现HandlerInterceptor，拦截请求并设置ID,如果请求上下文已经有ID则继承过来，
记得请求之后要清空上下文的ID;
@Component
public class TraceInterceptor implements HandlerInterceptor {
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
//如果有上层调用就用上层的ID
String traceId = request.getHeader(TraceIdUtil.TRACE_ID);
if (!StringUtils.hasLength(traceId)) {
TraceIdUtil.setTraceId(TraceIdUtil.generateTraceId());
} else {
TraceIdUtil.setTraceId(traceId);
}
return HandlerInterceptor.super.preHandle(request, response, handler);
}
@Override
public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception {
HandlerInterceptor.super.postHandle(request, response, handler, modelAndView);
}
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
HandlerInterceptor.super.afterCompletion(request, response, handler, ex);
//请求完成，移除id
TraceIdUtil.remove();
}
}
3、将拦截器TraceInterceptor，注册到应用中，不然不生效。
@Configuration
public class InterceptorConfig implements WebMvcConfigurer {
private Logger logger = LoggerFactory.getLogger(InterceptorConfig.class);
//通过引入数组，将所有的拦截器实现都注册到应用，逐个addInterceptor也是可以的
@Resource
private List<HandlerInterceptor> handlerInterceptorList;
@Override
public void addInterceptors(InterceptorRegistry registry) {
WebMvcConfigurer.super.addInterceptors(registry);
for (HandlerInterceptor handlerInterceptor : handlerInterceptorList) {
logger.info("interceptor class={}",handlerInterceptor.getClass());
registry.addInterceptor(handlerInterceptor);
}
}
}配置文件实现打印变量
第一修改日志配置文件，打印MDC里面的变量如下，
注意看 [%X{reqId}] 这是将上下文里面的reqId变量打印出来。和上面的工具类里面的变量一致
<configuration>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern> %d{HH:mm:ss.SSS} [%thread] %-5level [%X{reqId}] %logger{36} - %msg%n</pattern>
</encoder>
</appender>
<logger name="log.config" level="INFO"/>
<root level="INFO">
<appender-ref ref="STDOUT" />
</root>
</configuration>查看日志
空行分隔开的两次请求，reqId分别是
38fc74f8ed174943a19e97d692f3cf8d，
62298a4482d94f4ebfdd0102313fb63f；
22:49:49.900 [http-nio-9090-exec-2] INFO [38fc74f8ed174943a19e97d692f3cf8d] net.img.HelloController - getuser controller
22:49:49.900 [http-nio-9090-exec-2] INFO [38fc74f8ed174943a19e97d692f3cf8d] net.img.biz.HelloBiz - getuser biz
22:49:49.936 [ForkJoinPool.commonPool-worker-9] INFO [] net.img.biz.HelloBiz - async log
22:49:58.350 [http-nio-9090-exec-3] INFO [62298a4482d94f4ebfdd0102313fb63f] net.img.HelloController - getuser controller
22:49:58.351 [http-nio-9090-exec-3] INFO [62298a4482d94f4ebfdd0102313fb63f] net.img.biz.HelloBiz - getuser biz
22:49:58.351 [ForkJoinPool.commonPool-worker-9] INFO [] net.img.biz.HelloBiz - async log疑问
大家看到有一行日志async log，没有输出reqId，为什么？由于这行是重启了一个线程导致的上下文丢失，看代码
@Component
public class HelloBiz {
private Logger logger = LoggerFactory.getLogger(HelloBiz.class);
@Resource
private SysUserMapper sysUserMapper;
public SysUserEntity getUser(Long userId) {
logger.info("getuser biz");
CompletableFuture.runAsync(() -> {
logger.info("async log");
});
return sysUserMapper.selectByPrimaryKey(userId);
}
}如何解决呢？将reqId传到新线程的上下文中如下
@Component
public class HelloBiz {
private Logger logger = LoggerFactory.getLogger(HelloBiz.class);
@Resource
private SysUserMapper sysUserMapper;
public SysUserEntity getUser(Long userId) {
logger.info("getuser biz");
//取出来reqId,在线程执行前put到MDC
String traceId = TraceIdUtil.getTraceId();
CompletableFuture.runAsync(() -> {
MDC.put(TraceIdUtil.TRACE_ID, traceId);
logger.info("async log");
MDC.clear();
});
return sysUserMapper.selectByPrimaryKey(userId);
}
}新的日志如下
22:58:20.575 [http-nio-9090-exec-2] INFO [6068838d07f74f4e84b8dcc8ac88f951] net.img.HelloController - getuser controller
22:58:20.575 [http-nio-9090-exec-2] INFO [6068838d07f74f4e84b8dcc8ac88f951] net.img.biz.HelloBiz - getuser biz
22:58:20.680 [ForkJoinPool.commonPool-worker-9] INFO [6068838d07f74f4e84b8dcc8ac88f951] net.img.biz.HelloBiz - async log
22:58:28.716 [http-nio-9090-exec-3] INFO [5057bd3e4c3b4fb884578afbe284185e] net.img.HelloController - getuser controller
22:58:28.716 [http-nio-9090-exec-3] INFO [5057bd3e4c3b4fb884578afbe284185e] net.img.biz.HelloBiz - getuser biz
22:58:28.716 [ForkJoinPool.commonPool-worker-9] INFO [5057bd3e4c3b4fb884578afbe284185e] net.img.biz.HelloBiz - async log 更优雅一点可以自己包装一下多线程或线程池；给个简单例子
包装类。
public class FutureProxy<T> {
public Void run(Runnable runnable) {
String traceId = TraceIdUtil.getTraceId();
CompletableFuture.runAsync(() -> {
MDC.put(TraceIdUtil.TRACE_ID, traceId);
runnable.run();
MDC.clear();
});
return null;
}
}改一下上面的代码，效果一样
@Component
public class HelloBiz {
private Logger logger = LoggerFactory.getLogger(HelloBiz.class);
@Resource
private SysUserMapper sysUserMapper;
public SysUserEntity getUser(Long userId) {
logger.info("getuser biz");
new FutureProxy<Void>().run(() -> logger.info("async log"));
return sysUserMapper.selectByPrimaryKey(userId);
}
}© 版权声明
文章版权归作者所有，未经允许请勿转载。如内容涉嫌侵权，请在本页底部进入<联系我们>进行举报投诉!
THE END
- 最新
- 最热
只看作者