前言

Github:https://github.com/HealerJean

博客:http://blog.healerjean.com

一、日志格式

1)log4j

%d{yyyy-MM-dd HH:mm:ss} %-5level -[%-32X{REQ_UID}]- %msg%xEx %logger{36}.%M[%L]%n

2)logback

%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level -[%-32X{REQ_UID}] - %msg  -%logger{50}.%M[%L]%n

二、日志打印案例

1、接口调用-需抛异常

@LogIndex
List<SignOutWhiteConfigBatchDto> queryPerson(MerchantSignOutWhiteConfigQueryListReq request) {

  ListResponse<SignOutWhiteConfigBatchDto> response;
  try {
    response = venderSignOutWhiteConfigResource.queryPerson(request);

  } catch (Exception e) {
    log.error("UserService#queryPerson] ERROR, request:{}, e:{}", JSON.toJSONString(request), ExceptionUtils.getStackTrace(e));
    throw new ApiException(ErrorCodeEnum.ERROR_CODE_1011.getCode(), e.getMessage());
  }

  if (response != null && Boolean.TRUE.equals(response.getSuccess())) {
    //log.info("UserService#queryPerson] SUCCESS, request:{}, response:{}", JSON.toJSONString(request), JSON.toJSONString(response));
    return response.getValues();
  }

  log.error("UserService#queryPerson] FAIL, request:{}, response:{}", JSON.toJSONString(request), JSON.toJSONString(response));
  throw new ApiDataException(ErrorCodeEnum.ERROR_CODE_1012.getCode(), response == null ? ErrorCodeEnum.ERROR_CODE_1012.getMessage() : response.getMsg());
}

2、接口调用-可兜底

@LogIndex
public List<Person> queryPerson(List<String> userIds) {
  try {
    UserResponse response  = userServiceThrift.queryPerson(userIds);
    if (response != null && response.isSuccess() && CollectionUtils.isNotEmpty(response.getList())) {
      return res.getList();
    }
    log.error("[UserService#queryPerson] fail, userIds:{}, signInsuranceInfoQueryRes:{} ", 
              JsonUtils.toJsonString(res), JsonUtils.toJsonString(response));
  } catch (Exception e) {
    log.error("[UserService#queryPerson] error, userIds:{}, e:{} ",
              JsonUtils.toJsonString(userIds), ExceptionUtils.getStackTrace(e));
  }
  return null;
}

3、无切面日志-可兜底

public List<Person> queryPerson(List<String> userIds) {
  try {
    UserResponse response  = userServiceThrift.queryPerson(userIds);
    if (response != null && response.isSuccess() && CollectionUtils.isNotEmpty(response.getList())) {
      log.info("[UserService#queryPerson] success, userIds:{}, signInsuranceInfoQueryRes:{} ", 
               JsonUtils.toJsonString(res), JsonUtils.toJsonString(response));
      return res.getList();
    }
    log.error("[UserService#queryPerson] fail, userIds:{}, signInsuranceInfoQueryRes:{} ", 
              JsonUtils.toJsonString(res), JsonUtils.toJsonString(response));
  } catch (Exception e) {
    log.error("[UserService#queryPerson] error, userIds:{}, e:{} ",
              JsonUtils.toJsonString(userIds), ExceptionUtils.getStackTrace(e));
  }
  return null;
}

三、工具:切面打印接口出入参

1、LogAspect

1)LogIndex

import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;

@Target({ElementType.METHOD, ElementType.TYPE})
@Retention(RetentionPolicy.RUNTIME)
public @interface LogIndex {

    /**
     * 是否打印入参日志,默认是
     */
    boolean reqFlag() default true;

    /**
     * 是否打印出参日志,默认是
     */
    boolean resFlag() default true;

}

2)DynamicLogConfiguration

package com.hlj.proj.config;

import lombok.Data;
import lombok.extern.slf4j.Slf4j;
import org.springframework.context.annotation.Configuration;
import org.springframework.util.CollectionUtils;

import java.util.HashMap;
import java.util.Map;


@Slf4j
@Data
@Configuration
public class DynamicLogConfiguration {

    /**
     * 入参是否打印 举例:com.hlj.proj.controller.Log4j2Controller.log4j2
     */
    private Map<String, Boolean> reqPrintFlag;

    /**
     * 出参是否打印 举例:com.hlj.proj.controller.Log4j2Controller.log4j2
     */
    private Map<String, Boolean> resPrintFlag;

    /**
     * getReqPrintFlag
     */
    public Map<String, Boolean> getReqPrintFlag() {
        if (CollectionUtils.isEmpty(reqPrintFlag)) {
            return new HashMap<>(16);
        }
        return reqPrintFlag;
    }

    /**
     * getResPrintFlag
     */
    public Map<String, Boolean> getResPrintFlag() {
        if (CollectionUtils.isEmpty(resPrintFlag)) {
            return new HashMap<>(16);
        }
        return resPrintFlag;
    }
}

3)LogAspect

package com.hlj.proj.aspect;

import com.hlj.proj.config.DynamicLogConfiguration;
import com.hlj.proj.utils.JsonUtils;
import lombok.extern.slf4j.Slf4j;
import org.apache.commons.lang3.exception.ExceptionUtils;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.Signature;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.reflect.MethodSignature;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;

import javax.annotation.Resource;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.lang.reflect.Method;
import java.lang.reflect.Parameter;
import java.util.*;

/**
 * @author zhangyujin
 * @date 2021/11/9  5:24 下午
 * @desciption 切面日志
 */
@Slf4j
@Component
@Aspect
@Order(2)
public class LogAspect {


    /**
     * dynamicLogConfiguration
     */
    @Resource
    private DynamicLogConfiguration dynamicLogConfiguration;


    @Around(value = "(execution(* *(..)) && @annotation(logIndex))", argNames = "pjp,logIndex")
    public Object printLog(final ProceedingJoinPoint pjp, LogIndex logIndex) throws Throwable {
        Object[] args = pjp.getArgs();
        Signature sig = pjp.getSignature();
        long start = System.currentTimeMillis();
        Method method = null;
        Object result;
        Object reqParams;
        Map<String, Object> map = new HashMap<>(8);
        try {
            String    methodName = pjp.getSignature().getName();
            String  className = sig.getDeclaringTypeName();
            if ((sig instanceof MethodSignature)) {
                MethodSignature signature = (MethodSignature) sig;
                Object target = pjp.getTarget();
                method = target.getClass().getMethod(signature.getName(), signature.getParameterTypes());
            } else {
                log.error("signature is not instanceof MethodSignature!");
            }

            if (method == null) {
                return pjp.proceed();
            }

            String key = className + "." + methodName;
            map.put("method", key);

            Boolean reqPrintFlag = dynamicLogConfiguration.getReqPrintFlag().get(key);
            if (Objects.nonNull(reqPrintFlag) && Boolean.TRUE.equals(reqPrintFlag)){
                reqParams = getRequestParams(args, method.getParameters());
                map.put("req", reqParams);
            }
            if (Objects.isNull(reqPrintFlag) && Boolean.TRUE.equals(logIndex.reqFlag())) {
                reqParams = getRequestParams(args, method.getParameters());
                map.put("req", reqParams);
            }

            result = pjp.proceed();

            Boolean resPrintFlag = dynamicLogConfiguration.getResPrintFlag().get(key);
            if (Objects.nonNull(resPrintFlag) && Boolean.TRUE.equals(resPrintFlag)){
                map.put("res", result);
            }
            if (Objects.isNull(resPrintFlag) && Boolean.TRUE.equals(logIndex.resFlag())) {
                map.put("res", result);
            }
        } finally {
            long timeCost = System.currentTimeMillis() - start;
            map.put("timeCost", timeCost + "ms");
            log.info("LogAspect:{}", JsonUtils.toJsonString(map));
        }
        return result;
    }

    /**
     * 重构请求参数
     *
     * @param args       参数
     * @param parameters 参数名
     * @return 重构后的请求参数
     */
    public Object getRequestParams(Object[] args, Parameter[] parameters) {
        if (Objects.isNull(args)) {
            return null;
        }
        if (args.length == 1 && !(args[0] instanceof HttpServletRequest) && !(args[0] instanceof HttpServletResponse)) {
            return args[0];
        }

        List<Object> result = new ArrayList<>();
        try {
            for (int i = 0; i < args.length; i++) {
                Object param = args[i];
                if (param instanceof HttpServletRequest) {
                    result.add("HttpServletRequest");
                    continue;
                }
                if (param instanceof HttpServletResponse) {
                    result.add("HttpServletResponse");
                    continue;
                }
                Map<Object, Object> map = new HashMap<>(2);
                map.put(parameters[i].getName(), param);
                result.add(map);
            }
        } catch (Exception e) {
            log.warn("LogAspect getRequestParams error:{}", ExceptionUtils.getStackTrace(e));
        }
        return result;
    }
}

4)TraceIdAspect

@Aspect
@Component
@Slf4j
@Order(1)
public class TraceIdAspect {

    private static final String TRACE_ID_NAME = "REQ_UID";

    @Around("execution(* com.hlj.proj.controller.*Controller.*(..))")
    public Object traceIdSet(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
        String traceId = MDC.get(TRACE_ID_NAME);
        if (StringUtils.isBlank(traceId)) {
            MDC.put(TRACE_ID_NAME, UUID.randomUUID().toString().replace("-", ""));
        }
        try {
            return proceedingJoinPoint.proceed();
        } catch (Exception e) {
            Signature sig = proceedingJoinPoint.getSignature();
            String className = sig.getDeclaringTypeName();
            String methodName = proceedingJoinPoint.getSignature().getName();
            log.error("[{}.{}] error:{} ", className, methodName, ExceptionUtils.getStackTrace(e));
            throw e;
        } finally {
            MDC.remove(TRACE_ID_NAME);
        }
    }
}

四、工具:第三方接口调用出入参日志打印

1、Function

1)ThirdInvokeLogAspect

package com.hlj.proj.service;


import com.hlj.proj.utils.JsonUtils;
import org.apache.commons.lang3.StringUtils;
import org.apache.commons.lang3.exception.ExceptionUtils;
import org.slf4j.Logger;
import org.springframework.boot.logging.LogLevel;

import java.util.HashMap;
import java.util.Map;
import java.util.function.Function;

/**
 * InvokeUtils
 *
 * @author healerjean
 * @date 2021/6/23  9:21 下午.
 */
public class InvokeUtils {


    /**
     * call
     *
     * @param method   method
     * @param req      req
     * @param function function
     * @param logger   logger
     * @return {@link Res}
     */
    public static <Req, Res> Res call(String method, Req req, Function<Req, Res> function, Logger logger) {
        return call(method, req, function, logger, null);
    }


    /**
     * call
     *
     * @param methodName methodName
     * @param req        req
     * @param function   function
     * @param logger     logger
     * @param level      level
     * @return {@link Res}
     */
    public static <Req, Res> Res call(String methodName, Req req, Function<Req, Res> function, Logger logger, LogLevel level) {
        Res res = null;
        String stackTrace = null;
        long startTime = System.currentTimeMillis();
        try {
            res = function.apply(req);
            level = level != null ? level : LogLevel.INFO;
        } catch (Exception throwable) {
            stackTrace = ExceptionUtils.getStackTrace(throwable);
            level = level != null ? level : LogLevel.ERROR;
        } finally {
            log(methodName, req, res, stackTrace, startTime, logger, level);
        }
        return res;
    }


    /**
     * log
     *
     * @param method        method
     * @param requestParam  requestParam
     * @param responseParam responseParam
     * @param stackTrace    stackTrace
     * @param startTime     startTime
     * @param log           log
     * @param level         level
     */
    private static void log(String method, Object requestParam, Object responseParam, String stackTrace, long startTime, Logger log, LogLevel level) {
        try {
            long timeCost = System.currentTimeMillis() - startTime;
            Map<String, Object> map = new HashMap<>();
            map.put("method", method);
            map.put("requestParams", requestParam);
            map.put("responseParams", responseParam);
            map.put("timeCost", timeCost + "ms");
            if (StringUtils.isNotBlank(stackTrace)) {
                map.put("stackTrace", stackTrace);
            }
            switch (level) {
                case DEBUG:
                    log.debug("InvokeUtils:{}", JsonUtils.toJsonString(map));
                    break;
                case INFO:
                    log.info("InvokeUtils:{}", JsonUtils.toJsonString(map));
                    break;
                case WARN:
                    log.warn("InvokeUtils:{}", JsonUtils.toJsonString(map));
                    break;
                case ERROR:
                    log.error("InvokeUtils:{}", JsonUtils.toJsonString(map));
                    break;
                default:
                    log.info("InvokeUtils:{}", JsonUtils.toJsonString(map));
                    break;
            }
        } catch (Exception e) {
            log.error("InvokeUtils {}", ExceptionUtils.getStackTrace(e));
        }
    }
}


2、验证

@Test
public void test() {
    LogCallTestService logCallTestService = new LogCallTestService();
    LogCallTestService.RequestDTO requestDTO = new LogCallTestService.RequestDTO();
    requestDTO.setName("healerjean");
    requestDTO.setAge(1L);
    LogCallTestService.ResponseDTO res = InvokeUtils.call("invokeMethod", requestDTO,
                                                          logCallTestService::invokeMethod, 
                                                          log);

    res = InvokeUtils.call("invokeMethod", requestDTO, logCallTestService::invokeMethod, log, 
                           LogLevel.DEBUG);
  
    res = InvokeUtils.call("invokeMethod", requestDTO, logCallTestService::invokeMethod, log, 
                           LogLevel.INFO);
  
  	res = InvokeUtils.call("invokeMethod", requestDTO, logCallTestService::invokeMethod, log, 
                           LogLevel.WARN);
  
    res = InvokeUtils.call("invokeMethod", requestDTO, logCallTestService::invokeMethod, log, 
                           LogLevel.ERROR);
}

五、日志唯一标识追踪

1、Controller 过滤器 Log4j2ReqUidFilter

package com.healerjean.proj.config.filter;


import org.slf4j.MDC;

import javax.servlet.*;
import java.io.IOException;
import java.util.UUID;

/**
 * @author HealerJean
 * @ClassName Log4j2Filter
 * @date 2020/6/15  20:12.
 * @Description
 */
public class Log4j2ReqUidFilter implements Filter {

    private static final String REQ_UID = "REQ_UID";
    private FilterConfig filterConfig;


    @Override
    public void init(FilterConfig filterConfig) throws ServletException {
        this.filterConfig = filterConfig;
    }

    @Override
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {
        MDC.put(REQ_UID, UUID.randomUUID().toString().replace("-", ""));
        filterChain.doFilter(servletRequest, servletResponse);
        MDC.remove(REQ_UID);
    }

    @Override
    public void destroy() {
        this.filterConfig = null;
    }

}

@Bean
public FilterRegistrationBean<Log4j2ReqUidFilter> log4j2ReqUidFilter() {
    FilterRegistrationBean<Log4j2ReqUidFilter> fitler = new FilterRegistrationBean<>();
    fitler.setFilter(new Log4j2ReqUidFilter());
    fitler.addUrlPatterns("/*");
    fitler.setName("log4j2ReqUidFilter");
    fitler.setDispatcherTypes(DispatcherType.REQUEST);
    return fitler;
}

2、dubbo 日志追踪

1)服务提供者

a、aop 切面 pom依赖

<!-- aop 切面 -->
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-aop</artifactId>
</dependency>

b、ServiceLogAspect接口出入参日志打印

package com.healerjean.proj.config.aspect;

import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.Signature;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;


@Aspect
@Component
@Slf4j
@Order(1)
public class ServiceLogAspect {

    @Around("execution(* com.healerjean.proj.service.*Service.*(..))")
    public Object handleControllerLog(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
        Signature signature = proceedingJoinPoint.getSignature();
        String className = signature.getDeclaringTypeName();
        String methodName = signature.getName();
        Object[] args = proceedingJoinPoint.getArgs();
        long start = System.currentTimeMillis();
        try {
            log.info("请求开始:类名:【{}】,方法名:【{}】, 参数:【{}】", className, methodName, args);
            Object result = proceedingJoinPoint.proceed();
            long timeCost = System.currentTimeMillis() - start;
            log.info("请求结束:类名:【{}】, 方法名:【{}】, 参数:【{}】, 返回值:{}, 耗时:{}ms。", className, methodName, args, result, timeCost);
            return result;
        } catch (Exception e) {
            long timeCost = System.currentTimeMillis() - start;
            log.info("请求出错:类名:【{}】,方法名:【{}】, 参数:【{}】, 耗时:【{}】ms。", className, methodName, args, timeCost);
            throw e;
        }
    }
}

c、ProviderRpcTraceFilterdubbo日志追踪过滤器

package com.healerjean.proj.config.dubbo;

import com.alibaba.dubbo.common.Constants;
import com.alibaba.dubbo.common.extension.Activate;
import com.alibaba.dubbo.rpc.*;
import com.alibaba.dubbo.rpc.protocol.dubbo.filter.FutureFilter;
import org.apache.commons.lang3.StringUtils;
import org.slf4j.MDC;

import java.util.UUID;

@Activate(group = Constants.PROVIDER, order = 1)
public class ProviderRpcTraceFilter extends FutureFilter {


    private static final String DUBBO_REQ_UID = "REQ_UID";

    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
        String reqUid = RpcContext.getContext().getAttachment(DUBBO_REQ_UID);
        if (StringUtils.isBlank(reqUid)) {
            //传递丢失
            reqUid = "CUSTOM:" + UUID.randomUUID().toString().replace("-", "");
        }
        MDC.put(DUBBO_REQ_UID, reqUid);
        RpcContext.getContext().setAttachment(DUBBO_REQ_UID, reqUid);
        try {
            return invoker.invoke(invocation);
        } finally {
            MDC.remove(DUBBO_REQ_UID);
        }
    }
}

d、配置dubbo过滤器

![image-20200616112740541]https://raw.githubusercontent.com/HealerJean/HealerJean.github.io/master/blogImages/image-20200616112740541.png)

com.alibaba.dubbo.rpc.Filter

ProviderRpcTraceFilter=com.healerjean.proj.config.dubbo.ProviderRpcTraceFilter

2)服务消费者

a、aop 切面 pom 依赖

<!-- aop 切面 -->
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-aop</artifactId>
</dependency>

b、ControllerLogAspect controller出入参打印

package com.healerjean.proj.config.aspect;

import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.Signature;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;


@Aspect
@Component
@Slf4j
@Order(1)
public class ControllerLogAspect {

    @Around("execution(* com.healerjean.proj.controller.*Controller.*(..))")
    public Object handleControllerLog(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
        Signature signature = proceedingJoinPoint.getSignature();
        String className = signature.getDeclaringTypeName();
        String methodName = signature.getName();
        Object[] args = proceedingJoinPoint.getArgs();
        long start = System.currentTimeMillis();
        try {
            log.info("请求开始:类名:【{}】,方法名:【{}】, 参数:【{}】", className, methodName, args);
            Object result = proceedingJoinPoint.proceed();
            long timeCost = System.currentTimeMillis() - start;
            log.info("请求结束:类名:【{}】, 方法名:【{}】, 参数:【{}】, 返回值:{}, 耗时:{}ms。", className, methodName, args, result, timeCost);
            return result;
        } catch (Exception e) {
            long timeCost = System.currentTimeMillis() - start;
            log.info("请求出错:类名:【{}】,方法名:【{}】, 参数:【{}】, 耗时:【{}】ms。", className, methodName, args, timeCost);
            throw e;
        }
    }
}

c、日志追踪过滤器

package com.healerjean.proj.config.filter;


import org.slf4j.MDC;

import javax.servlet.*;
import java.io.IOException;
import java.util.UUID;

/**
 * @author HealerJean
 * @ClassName Log4j2Filter
 * @date 2020/6/15  20:12.
 * @Description
 */
public class Log4j2ReqUidFilter implements Filter {

    private static final String REQ_UID = "REQ_UID";
    private FilterConfig filterConfig;


    @Override
    public void init(FilterConfig filterConfig) throws ServletException {
        this.filterConfig = filterConfig;
    }

    @Override
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException {
        MDC.put(REQ_UID, UUID.randomUUID().toString().replace("-", ""));
        filterChain.doFilter(servletRequest, servletResponse);
        MDC.remove(REQ_UID);
    }

    @Override
    public void destroy() {
        this.filterConfig = null;
    }



}



@Configuration
public class InterceptorConfig extends WebMvcConfigurerAdapter {

    @Bean
    public FilterRegistrationBean log4j2ReqUidFilter() {
        FilterRegistrationBean fitler = new FilterRegistrationBean();
        fitler.setFilter(new Log4j2ReqUidFilter());
        fitler.addUrlPatterns("/*");
        fitler.setName("Log4j2ReqUidFilter");
        fitler.setDispatcherTypes(DispatcherType.REQUEST);
        return fitler;
    }
}

d、ConsumerRpcTraceFilterdubbo日志追踪过滤器

package com.healerjean.proj.config.dubbo;

import com.alibaba.dubbo.common.Constants;
import com.alibaba.dubbo.common.extension.Activate;
import com.alibaba.dubbo.rpc.*;
import com.alibaba.dubbo.rpc.protocol.dubbo.filter.FutureFilter;
import org.apache.commons.lang3.StringUtils;
import org.slf4j.MDC;

import java.util.UUID;

@Activate(group = Constants.CONSUMER, order = 1)
public class ConsumerRpcTraceFilter extends FutureFilter {


    private static final String DUBBO_REQ_UID = "REQ_UID";

    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
        RpcContext.getContext().setAttachment(DUBBO_REQ_UID, MDC.get(DUBBO_REQ_UID));
        return invoker.invoke(invocation);
    }
}

e、配置dubbo过滤器

![image-20200616113137513]https://raw.githubusercontent.com/HealerJean/HealerJean.github.io/master/blogImages/image-20200616113137513.png)

com.alibaba.dubbo.rpc.Filter

ConsumerRpcTraceFilter=com.healerjean.proj.config.dubbo.ConsumerRpcTraceFilter

ContactAuthor