日志链路追踪

摘要

在我们的系统中需要记录日志，包括接口、方法的调用用户信息、用时、参数等。分布式环境中通过dubbo调用rpc服务，需要提供全局traceId追踪完整调用链路。

---

解决方案

通过拦截器使用ThreadLocal记录用户信息，通过注解+aspect的方式记录日志。同时因为是分布式系统，dubbo服务，日志由各个系统记录，不论是记录到统一的数据库还是记录到各自的log文件中，为了方便各个系统间查看完整的日志链路，需要生成全局的traceId，方便实现全链路追踪。

• request入口添加拦截器，采用slf4j提供的MDC记录用户信息
• 自定义注解和aspect，添加环绕切面，被注解的方法记录参数、结果、用时等
• 添加dubbo拦截器，通过setAttachment设置traceId和用户信息

---

实现

1. servlet拦截器
   拦截请求，生成全局TraceId、记录用户信息至MDC中

   public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain)
               throws IOException, ServletException {
           String userId= SysUtil.getCurUserId((HttpServletRequest)request);
           if(!StringUtils.isEmpty(userId)){
               UserDTO user= userService.getUserById(userId);
               if(user!=null){
                   MDCUtil.setUserName(user.getUserName());
               }
           }
           MDCUtil.setUserId(userId);
           MDCUtil.setTraceId();
           chain.doFilter(request, response);
       }
   

2. 自定义注解添加日志描述

   @Documented
   @Target({ElementType.METHOD})
   @Retention(RetentionPolicy.RUNTIME)
   public @interface LogRecord {
       String description() default "" ;
   }
   

   需要记录日志的方法添加注解

   @LogRecord(description = "根据用户id查询用户角色列表")
   public List<RoleDTO> listUserRole(String userId){
       UserDTO user=getUserById(userId);
       if(user==null){
           return new ArrayList<>();
       }
       //获取用户关联的角色id
       List<String> roleIds=getUserService().listUserRoleIds(userId);
       //根据角色id查询角色详情
       return getUserService().listRoleByRoleId(roleIds);
   }
   

3. 切面记录日志信息
   Aspect为所有添加了@LogRecord注解的方法添加环绕切面，记录执行参数、从MDC获取用户信息和traceId、计算方法执行时间、记录执行结果。

   @Aspect
   @Order(-6)
   @Component
   public class LogRecordAspect {
       @Autowired
       private LogServiceImpl logService;
   
   
       @Pointcut("@annotation(com.ym.provider.aop.LogRecord)")
       public void logAspect(){
           //记录日志
       }
   
       @Around("logAspect()")
       public Object recordLog(ProceedingJoinPoint joinPoint) throws Throwable {
           MethodSignature signature = (MethodSignature)joinPoint.getSignature();
           Method method = signature.getMethod();
           LogRecord auditLog = method.getAnnotation(LogRecord.class);
           String description= auditLog.description();
           Map<String,Object> param=formatParam(joinPoint);
           Long startTime=System.currentTimeMillis();
           Object proceed = joinPoint.proceed();
           String result="void";
           if(!signature.getReturnType().equals(void.class)){
               result=JSONObject.toJSONString(proceed);
           }
           Long endTime=System.currentTimeMillis();
           saveLog(param,result,method.getName(),description,endTime-startTime);
           return proceed;
       }
       
       /**
        * 记录日志信息
        * @param param
        * @param result
        * @param methodName
        * @param description
        * @param spendTime
        */
       public void saveLog(Map<String,Object> param,String result,String methodName,String description,Long spendTime){
           LogEntity log = new LogEntity();
           log.setUserId(MDCUtil.getUserId());
           log.setUserName(MDCUtil.getUserName());
           log.setMethodName(methodName);
           log.setTraceId(MDCUtil.getTraceId());
           log.setDescription(description);
           log.setSpendTime(spendTime);
           log.setParam(JSONObject.toJSONString(param));
           log.setResult(result);
           log.setOptTime(new Date());
           logService.save(log);
       }
   
       public Map<String,Object> formatParam(JoinPoint joinPoint){
           Map<String,Object> res=new HashMap();
           MethodSignature signature = (MethodSignature) joinPoint.getSignature();
           String[] paramNames = signature.getParameterNames();
           if(paramNames==null || paramNames.length==0){
               return res;
           }
           Object[] params=joinPoint.getArgs();
           for (int i = 0; i < paramNames.length; i++) {
               res.put(paramNames[i],params[i]);
           }
           return res;
       }
   }
   

4. dubbo拦截器
   通过dubbo拦截器
   资源文件夹下创建 META-INF/dubbo 文件夹，创建com.alibaba.dubbo.rpc.Filter 文件，并编辑文件内容traceIdFilter=com.ym.filter.TraceIdFilter
   调用服务时将traceId及用户信息添加至RpcContext中
   服务被调用时从RpcContext中获取traceId及用户信息转存至MDC中

   @Activate(group = {Constants.CONSUMER, Constants.PROVIDER} , order = -9999)
   public class TraceIdFilter implements Filter {
       @Override
       public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
           String traceId = RpcContext.getContext().getAttachment("traceId");
           if (!StringUtils.isEmpty(traceId) ) {
               MDCUtil.setTraceId(traceId);
               MDCUtil.setUserId(RpcContext.getContext().getAttachment("userId"));
               MDCUtil.setUserName(RpcContext.getContext().getAttachment("userName"));
           } else {
               RpcContext.getContext().setAttachment("traceId", MDCUtil.getTraceId());
               RpcContext.getContext().setAttachment("userId", MDCUtil.getUserId());
               RpcContext.getContext().setAttachment("userName", MDCUtil.getUserName());
           }
           return invoker.invoke(invocation);
       }
   }
   

---

效果

1. 单个应用内部调用链
   
2. 应用间调用链