Java

SpringMVC - 使用切面打请求返回参数日志 [推荐方案]

继续后端服务系列：

基于AOP统一打请求返回参数日志。

日志效果：

1
2
[01:10:08:004] [INFO] - com.tracenote.aspects.LogAspect.doAround(LogAspect.java:76) - Method: com.tracenote.api.controller.HelloWorld.helloUser，Method Description: , Request Args: [{"name":"zhang"}], Response Result  : {"name":"zhang"}
[01:10:08:005] [INFO] - com.tracenote.aspects.LogAspect.doAround(LogAspect.java:85) - Time Consuming: 121 ms

使用示例：

在需要自动打日志的地方加 @Log 注解。

1
2
3
4
5
6
@Log // (description = "xxxxx")
    @ResponseBody
    @RequestMapping("helloUser")
    public User helloUser(@RequestBody User user) {
        return userService.getUser(user);
    }

description 可省略。

实现：

Log.java

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
package com.tracenote.aspects;

import java.lang.annotation.*;

@Retention(RetentionPolicy.RUNTIME)
@Target({ElementType.METHOD})
@Documented
public @interface Log {

    /**
     * 自定义日志描述信息文案
     *
     * @return
     */
    String description() default "";
}

LogAspect.java

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
package com.tracenote.aspects;

import com.alibaba.fastjson.JSON;
import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.*;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;

import javax.servlet.http.HttpServletRequest;
import java.lang.reflect.Method;

@Slf4j
@Aspect
@Order(0)
@Component
//@Profile({"dev"}) //只对某个环境打印日志
public class LogAspect {
    private static final String LINE_SEPARATOR = System.lineSeparator();

    /**
     * 以自定义 @Log 注解作为切面入口
     */
    @Pointcut("execution(* *(..)) && @annotation(com.tracenote.aspects.Log)")
    public void Log() {
    }


    @Before("Log()")
    public void doBefore(JoinPoint joinPoint) throws Throwable {

        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();

        String methodDetailDescription = this.getAspectMethodLogDescJP(joinPoint);

//        log.info("------------------------------- start --------------------------");
//        /**
//         * 打印自定义方法描述
//         */
//        log.info("Method detail Description: {}", methodDetailDescription);
//        /**
//         * 打印请求入参
//         */
//        log.info("Request Args: {}", JSON.toJSONString(joinPoint.getArgs()));
//        /**
//         * 打印请求方式
//         */
//        log.info("Request method: {}", request.getMethod());
//        /**
//         * 打印请求 url
//         */
//        log.info("Request URL: {}", request.getRequestURL().toString());
//
//        /**
//         * 打印调用方法全路径以及执行方法
//         */
//        log.info("Request Class and Method: {}.{}", joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName());
    }


    @Around("Log()")
    public Object doAround(ProceedingJoinPoint joinPoint) throws Throwable {

        String aspectMethodLogDescPJ = getAspectMethodLogDescPJ(joinPoint);

        long startTime = System.currentTimeMillis();

        Object result = joinPoint.proceed();
        /**
         * 输出结果
         */
        log.info("Method: {}.{}，Method Description: {}, Request Args: {}, Response Result  : {}"
                , joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName()
                , aspectMethodLogDescPJ
                , JSON.toJSONString(joinPoint.getArgs())
                , JSON.toJSONString(result));

        /**
         * 方法执行耗时
         */
        log.info("Time Consuming: {} ms", System.currentTimeMillis() - startTime);

        return result;
    }


    @After("Log()")
    public void doAfter(JoinPoint joinPoint) throws Throwable {
//        log.info("------------------------------- End --------------------------" + LINE_SEPARATOR);
    }


    public String getAspectMethodLogDescJP(JoinPoint joinPoint) throws Exception {
        String targetName = joinPoint.getTarget().getClass().getName();
        String methodName = joinPoint.getSignature().getName();
        Object[] arguments = joinPoint.getArgs();
        return getAspectMethodLogDesc(targetName, methodName, arguments);
    }


    public String getAspectMethodLogDescPJ(ProceedingJoinPoint proceedingJoinPoint) throws Exception {
        String targetName = proceedingJoinPoint.getTarget().getClass().getName();
        String methodName = proceedingJoinPoint.getSignature().getName();
        Object[] arguments = proceedingJoinPoint.getArgs();
        return getAspectMethodLogDesc(targetName, methodName, arguments);
    }


    public String getAspectMethodLogDesc(String targetName, String methodName, Object[] arguments) throws Exception {
        Class targetClass = Class.forName(targetName);
        Method[] methods = targetClass.getMethods();
        StringBuilder description = new StringBuilder("");
        for (Method method : methods) {
            if (method.getName().equals(methodName)) {
                Class[] clazzs = method.getParameterTypes();
                if (clazzs.length == arguments.length) {
                    description.append(method.getAnnotation(Log.class).description());
                    break;
                }
            }
        }
        return description.toString();
    }
}

web.xml

1
<aop:aspectj-autoproxy/>

maven

1
2
3
4
5
<dependency>
    <groupId>org.aspectj</groupId>
    <artifactId>aspectjweaver</artifactId>
    <version>1.9.6</version>
</dependency>

这种打日志的方案在工程实践中比较常见。参考来源 https://zhuanlan.zhihu.com/p/161877472，并做了部分优化。

参考：