SpringBoot 如何在日志中增加 trace id 用于链路追踪

#SpringBoot 如何在日志中增加 trace id 用于链路追踪| 来源: 网络整理| 查看: 265

目录增加 logback 记录日志使用 AOP 统一控制输入输出使用 MDC 存储 trace id项目完整代码见：https://gitee.com/zhoumengkang/wechat-demo/tree/master/strace01增加 logback 记录日志

为什么大家都习惯用使用 logback-spring.xml而不是logback.log，因为使用前者名字，可以使用一些结合spring的特殊扩展功能。这里，暂时用不到，后面再用。

https://docs.spring.io/spring-boot/docs/2.6.1/reference/html/features.html#features.logging.logback-extensions

我们在资源目录下新建logback-spring.xml

${FILE_LOG_PATTERN} utf8

最重要的是FILE_LOG_PATTERN日志模板里面设置了[%X{TRACE_ID}]就可以从MDC里面获取TRACE_ID的值了

使用 AOP 统一控制输入输出@Component @Slf4j @Aspect public class ControllerHandler { private final static String TRACE_ID = "TRACE_ID"; @Pointcut("execution(public * com.example.demo.controller..*.*(..)) ") public void recordLog() { } @Before("recordLog()") public void before(JoinPoint point){ MDC.put(TRACE_ID, UUID.randomUUID().toString()); } @AfterReturning(pointcut = "recordLog()", returning = "responseData") public void after(JoinPoint point, ResponseData responseData){ responseData.setRequestId(MDC.get(TRACE_ID)); log.info(JSON.toJSONString(responseData)); } }

最重要的就是

MDC.put(TRACE_ID, UUID.randomUUID().toString());

这样就和上面日志模板里面的[%X{TRACE_ID}]对接上了。

增加一个控制器然后查看日志@RestController @RequestMapping("/user") @Slf4j public class UserController { @GetMapping("/{id}") public ResponseData detail(@PathVariable Long id){ Preconditions.checkNotNull(id, "id is null"); log.info("user id:{}", id); UserDTO userDTO = new UserDTO(); userDTO.setId(id); userDTO.setAge(20); userDTO.setUsername("加班写Bug"); return ResponseData.success(userDTO); } }

访问 http://localhost:8080/user/1001 查看日志

2021-12-04 21:57:34.723 INFO 48311 --- [http-nio-8080-exec-1] [aba37c62-5850-4da0-bfaf-89fa9c4282ea] c.e.demo.controller.UserController : user id:1001 2021-12-04 21:57:34.859 INFO 48311 --- [http-nio-8080-exec-1] [aba37c62-5850-4da0-bfaf-89fa9c4282ea] com.example.demo.aop.ControllerHandler : {"code":200,"data":{"age":20,"id":1001,"username":"加班写Bug"},"message":"OK","success":true,"traceId":"aba37c62-5850-4da0-bfaf-89fa9c4282ea"}

实际工作中，可能在访问这台 web 应用服务器之前已经有一些链路，比如有统一的网关层，或者被反向代理。trace id 的可能是需要从该应用的上游往下传递，这里以 nginx 反向代理过程中，在 header 里增加了Trace-Id字段为例

使用 curl 校验下是否生效

curl -H 'Trace-Id:123456' http://localhost:8080/user/1001 {"success":true,"code":200,"message":"OK","traceId":"123456","data":{"id":1001,"username":"加班写Bug","age":20}}

这里是举例说明，trace id 可以有更多的算法来校验其是否合法。

打印更完整的链路日志

打印 trace id 不是目标，能够通过 trace id 精准的定位问题、排查问题才是目的，所以最好是 input 和 output 都打印下。这里使用Around代替了刚刚的 before 和 after ，并且对控制器的异常直接在这里做了处理。

@Component @Slf4j @Aspect public class ControllerHandler { private final static String TRACE_ID = "TRACE_ID"; @Autowired HttpServletRequest request; @Pointcut("execution(public * com.example.demo.controller..*.*(..)) ") public void recordLog() { } public void setTraceId(){ if (request != null && request.getHeader("Trace-Id") != null) { MDC.put(TRACE_ID, request.getHeader("Trace-Id")); }else{ MDC.put(TRACE_ID, UUID.randomUUID().toString()); } } @Around("recordLog()") public Object record(ProceedingJoinPoint joinPoint) throws Throwable { setTraceId(); String classType = joinPoint.getTarget().getClass().getName(); Class clazz = Class.forName(classType); String clazzSimpleName = clazz.getSimpleName(); String methodName = joinPoint.getSignature().getName(); Signature signature = joinPoint.getSignature(); MethodSignature methodSignature = (MethodSignature) signature; String[] parameterNames = methodSignature.getParameterNames(); Object[] parameters = joinPoint.getArgs(); Map parameterMap = new LinkedHashMap(); for (int i = 0; i < parameters.length; i++) { String parameterName = parameterNames[i]; Object parameter = parameters[i]; parameterMap.put(parameterName, parameter); } String parametersJsonString = JSON.toJSONString(parameterMap, SerializerFeature.WriteMapNullValue); log.info("{}#{} args:{}", clazzSimpleName, methodName, parametersJsonString); Object response; try { response = joinPoint.proceed(joinPoint.getArgs()); } catch (Exception e) { log.error("{}#{}, exception:{}:", clazzSimpleName, methodName, e.getClass().getSimpleName(), e); ResponseData res = ResponseData.failure(ResponseCode.INTERNAL_ERROR); if (e instanceof IllegalArgumentException || e instanceof NullPointerException) { res.setCode(ResponseCode.BAD_REQUEST.getCode()); res.setMessage(e.getMessage()); }else if (e instanceof DemoRuntimeException) { res.setMessage(e.getMessage()); } response = res; } if (response instanceof ResponseData) { ((ResponseData) response).setTraceId(MDC.get(TRACE_ID)); } String resultJsonString = JSON.toJSONString(response, SerializerFeature.WriteMapNullValue, SerializerFeature.DisableCircularReferenceDetect); log.info("{}#{} response:{}", clazzSimpleName, methodName, resultJsonString); return response; } }

99% 的应用都不用考虑这点 I/O 性能的影响，真建议打上。再次访问 http://localhost:8080/user/1001 查看日志

2021-12-04 23:24:38.122 INFO 90186 --- [http-nio-8080-exec-1] [e334594c-5ae2-48fa-91dc-10528004f6d2] com.example.demo.aop.ControllerHandler : UserController#detail args:{"id":1001} 2021-12-04 23:24:38.141 INFO 90186 --- [http-nio-8080-exec-1] [e334594c-5ae2-48fa-91dc-10528004f6d2] c.e.demo.controller.UserController : user id:1001 2021-12-04 23:24:38.209 INFO 90186 --- [http-nio-8080-exec-1] [e334594c-5ae2-48fa-91dc-10528004f6d2] com.example.demo.aop.ControllerHandler : UserController#detail response:{"code":200,"data":{"age":20,"id":1001,"username":"加班写Bug"},"message":"OK","success":true,"traceId":"e334594c-5ae2-48fa-91dc-10528004f6d2"}

这样控制器里的log.info("user id:{}", id)就可以删掉了。

项目完整代码见：https://gitee.com/zhoumengkang/wechat-demo/tree/master/strace01

【本文地址】

公司简介

联系我们