文章发布在我的公众号
wechat_qrcodejpg

http log

本文旨在讨论如何利用 aop 打印 springboot http 日志,包括访问日志、接口返回 response,以及异常堆栈信息。

背景

为什么需要 log

有过线上问题排查经历的同学都知道,日志可以给你提供最直白、最明确的信息。此外,通过对日志的收集、审计,可以对 BI 以及系统健壮性提供建议。尤其是新系统上线之初,系统稳定性不足,更需要日志监控。

为什么不实用 Greys+access log

Greys 作为 Java 线上问题诊断工具,可以监控实时访问参数,但是对历史访问无记录,尤其是在前后分离 or 微服务架构下,日志是可以作为呈堂证供的存在。而 access log 不够灵活和强大。

方案优势

  1. 简化日志打印
  2. 统一的日志格式,可以配合收集机制
  3. 灵活,可以自由选择是否记录日志、是否忽略 response、是否忽略某些参数(如 file 参数显然不适合记录日志)、以及是否打印 header 参数
  4. 日志记录比例可配置(系统稳定,流量增大之后,可以通过配置降低记录比例)
  5. 方便回溯异常请求参数
  6. 记录接口耗时

实现

AOP- 面向切面编程

一句话描述,在 java 对象方法中增加切点,在不改变对象领域的前提下通过代理扩展功能。

切面选择

网上常见教程会选择拦截所有 http 请求,并打印 request.parameters。但是存在问题:

  1. 不够灵活,部分参数不想打印,如文件数据(过大)、敏感数据(身份证)等。
  2. 隐式的 aop,容易给维护人员造成疑惑。(个人习惯偏向于避免隐藏的 aop 逻辑)
  3. 部分参数通过 header 传输

因此,自定义日志输出@annotation HttpLog作为切点

/**
 * 用于打印http请求访问日志
 *
 * @author yuheng.wang
 */
@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface HttpLog {
    /**
     * 忽略参数,避免文件or无意义参数打印
     *
     * @return 忽略参数数组
     */
    String[] exclude() default {};

    /**
     * 需要打印的header参数
     *
     * @return header参数名数组
     */
    String[] headerParams() default {};

    boolean ignoreResponse() default false;
    
    /**
     * 日志记录比例
     *  >100 or < 0时,每次请求都会被记录
     *  = 0 时,不会记录
     */
    int percent() default 100;
}

@Aspect
@Slf4j
public class HttpLogHandler {

    @Pointcut("@annotation(wang.crick.study.httplog.annotation.HttpLog)")
    public void logAnnotation() {
    }
    
    private Optional<HttpLog> getLogAnnotation(JoinPoint joinPoint) {
    if (joinPoint instanceof MethodInvocationProceedingJoinPoint) {
        Signature signature = joinPoint.getSignature();
        if (signature instanceof MethodSignature) {
            MethodSignature methodSignature = (MethodSignature) signature;
            Method method = methodSignature.getMethod();
            if (method.isAnnotationPresent(HttpLog.class)) {
                return Optional.of(method.getAnnotation(HttpLog.class));
            }
        }
    }
        return Optional.empty();
    }
}

打印异常信息

  1. 为了方便回溯,定义 UUID 形式的 traceId,并通过 ThreadLocal 持有。
  2. 为了记录接口相应时间,定义 startTime,并通过 ThreadLocal 持有。
  3. AfterThrowing 方法不会阻碍 Exception 的抛出,不会影响全局异常捕获。
@AfterThrowing(throwing = "e", pointcut = "logAnnotation()")
public void throwing(JoinPoint joinPoint, Exception e) {
    try {
        Optional<HttpLog> httpLog = getLogAnnotation(joinPoint);
        httpLog.ifPresent(anno -> {
            if (!anno.ignoreResponse()) {
                log.info("ERROR_LOG. traceId:{}, cost:{}",
                        traceIdThreadLocal.get(), costTime(), e);
            }
        });
    } catch (Exception exception) {
        log.warn("print error log fail!", exception);
    } finally {
        startTimeThreadLocal.remove();
        traceIdThreadLocal.remove();
    }
}

打印 response

  1. 通过 JSONObject.toJSONString() 转换,因为 restful 接口常见为返回 json 格式。
  2. 需要判断是否忽略了 response 打印
@AfterReturning(returning = "restApiResponse", pointcut = "logAnnotation()")
public void response(JoinPoint joinPoint, Object restApiResponse) {
    try {
        Optional<HttpLog> httpLog = getLogAnnotation(joinPoint);
        httpLog.ifPresent(anno -> {
            if (!anno.ignoreResponse()) {
                log.info("RESPONSE_LOG. traceId:{}, result:{}, cost:{}",
                        traceIdThreadLocal.get(), JSONObject.toJSONString(restApiResponse), costTime());
            }
        });
    } catch (Exception exception) {
        log.warn("print response log fail!", exception);
    } finally {
        startTimeThreadLocal.remove();
        traceIdThreadLocal.remove();
    }
}

获取请求日志

获取 HttpServletRequest

重点在于获取 HttpServletRequest 对象,而 spring 已经很贴心的在 initContextHolders 时通过 RequestContextHolder 持有了 RequestAttributes 参数 (基于 ThreadLocal)。 所以我们可以很轻松的获取请求参数

private HttpServletRequest getRequest() {
    RequestAttributes ra = RequestContextHolder.getRequestAttributes();
    ServletRequestAttributes sra = (ServletRequestAttributes) ra;
    return sra.getRequest();
}

获取 RequestBody

!!上面获取参数的方式有一个缺陷,无法获取 RequestBody 参数,因为 RequestBody 是以流的形式读取,只能被读取一次,如果在 aop 中的提前读取了内容信息,后面的业务方法则无法获取。
一般的解决方案为封装一层 HttpServletRequestWrapper 暂存流的信息,实现多次读取。但是此种方案对需要修改 HttpServletRequest,侵入性较大,所以我们采取另一种方案,基于 aop+ 反射的特性获取 java 方法参数,遍历判断是否为 @RequestBody 参数。

private Optional<Object> getRequestBodyParam(JoinPoint joinPoint){
    if (joinPoint instanceof MethodInvocationProceedingJoinPoint) {
        Signature signature = joinPoint.getSignature();
        if (signature instanceof MethodSignature) {
            MethodSignature methodSignature = (MethodSignature) signature;
            Method method = methodSignature.getMethod();
            Parameter[] methodParameters = method.getParameters();
            if (null != methodParameters
                    && Arrays.stream(methodParameters).anyMatch(p-> AnnotationUtils.findAnnotation(p, RequestBody.class) != null)) {
                return Optional.of(joinPoint.getArgs());
            }
        }
    }
    return Optional.empty();
}

获取 uri

根据拦截规则不同,getServletPath()和 request.getPathInfo() 可能为空,简单的做一次健壮性判断。

private String getRequestPath(HttpServletRequest request) {
   return (null != request.getServletPath() && request.getServletPath().length() > 0)
           ? request.getServletPath() : request.getPathInfo();
    
}

日志记录百分比

  1. 接口请求量一般为平稳持续
  2. 并不需要十分精确的比例

所以通过接口访问时间戳 (startTime) 尾数进行判断

private boolean needLog(int percent, long startTimeMillis){
    if (percent< 0 || percent >= 100) {
        return true;
    } else if (percent == 0) {
        return false;
    } else {
        return percent > startTimeMillis % 100;
    }
}

使用

加载 HttpLogAspect 对象

  1. 可以在 @SpringBootApplication 类下直接加载,也可以在 HttpLogAspect 中增加 @Component 注解。
  2. 不需要显示声明 @EnableAspectJAutoProxy 注解
@Bean
public HttpLogAspect httpLogAspect(){
	return new HttpLogAspect();
}

Controller 配置日志打印

在 controller 中在接口方法中通过 HttpLog 配置,即可实现日志记录

@GetMapping("/log/pwdExcludeResponse/{id}")
@HttpLog(headerParams="username", ignoreResponse = true, percent = 50, exclude={"avatar"})
public RestApiResponse<User> getInfoWithPwd(@PathVariable("id") int id,
                                            @RequestParam("age") int age,
                                            @RequestParam("avatar") MultipartFile avatar,
                                            @RequestHeader("password") String password){
    User user = new User();
    user.setId(id);
    user.setPassword(password);
    user.setAge(age);
    return RestApiResponse.success(user);
}

效果

REQUEST_LOG. traceId:737001cf-f546-4092-9c77-f7762275ddcf. requestUrl: /user/log/7 -PARAMS- age: [6], 
RESPONSE_LOG. traceId:737001cf-f546-4092-9c77-f7762275ddcf, result:{"code":10000,"data":{"age":6,"id":7,"username":"8025373076402792850"}}, cost:171
REQUEST_LOG. traceId:8c907a7e-f36a-4ccc-a931-f167b55697ee. requestUrl: /user/log/pwd/0 -PARAMS- age: [7],  -HEADER_PARAMS- password: 6460630360418207541, 
RESPONSE_LOG. traceId:8c907a7e-f36a-4ccc-a931-f167b55697ee, result:{"code":10000,"data":{"id":0,"password":"6460630360418207541","username":"2250855379452327045"}}, cost:9

  • Java

    Java 是一种可以撰写跨平台应用软件的面向对象的程序设计语言,是由 Sun Microsystems 公司于 1995 年 5 月推出的。Java 技术具有卓越的通用性、高效性、平台移植性和安全性。

    2087 引用 • 6950 回帖 • 1118 关注
  • 日志
    24 引用 • 77 回帖
  • AOP
    11 引用 • 13 回帖
感谢    关注    收藏    赞同    反对    举报    分享