写个日志请求切面，前后端甩锅更方便

逃离我推掉我的手 2021-08-31 22:12 149阅读 0赞

点击上方 [Java后端][Java]，选择 设为星标

优质文章，及时送达

--------------------

最近项目进入联调阶段，服务层的接口需要和协议层进行交互，协议层需要将入参\[json字符串\]组装成服务层所需的json字符串，组装的过程中很容易出错。入参出错导致接口调试失败问题在联调中出现很多次，因此就想写一个请求日志切面把入参信息打印一下，同时协议层调用服务层接口名称对不上也出现了几次，通过请求日志切面就可以知道上层是否有没有发起调用，方便前后端甩锅还能拿出证据

### **写在前面** ###

本篇文章是实战性的，对于切面的原理不会讲解，只会简单介绍一下切面的知识点

### **切面介绍** ###

面向切面编程是一种编程范式，它作为OOP面向对象编程的一种补充，用于处理系统中分布于各个模块的横切关注点，比如**事务管理**、**权限控制**、**缓存控制**、**日志打印**等等。AOP把软件的功能模块分为两个部分：核心关注点和横切关注点。业务处理的主要功能为核心关注点，而非核心、需要拓展的功能为横切关注点。AOP的作用在于分离系统中的各种关注点，将核心关注点和横切关注点进行分离，使用切面有以下好处：

*  集中处理某一关注点/横切逻辑
 *  可以很方便的添加/删除关注点
 *  侵入性少，增强代码可读性及可维护性 因此当想打印请求日志时很容易想到切面，对控制层代码0侵入

### **切面的使用【基于注解】** ###

### @Aspect => 声明该类为一个注解类 ###

**切点注解：**

@Pointcut => 定义一个切点，可以简化代码

**通知注解：**

*  @Before => 在切点之前执行代码
 *  @After => 在切点之后执行代码
 *  @AfterReturning => 切点返回内容后执行代码，可以对切点的返回值进行封装
 *  @AfterThrowing => 切点抛出异常后执行
 *  @Around => 环绕，在切点前后执行代码

### 动手写一个请求日志切面 ###

### 使用@Pointcut定义切点 ###

@Pointcut("execution(* your_package.controller..*(..))")
    public void requestServer() {
    }

@Pointcut定义了一个切点，因为是请求日志切边，因此切点定义的是Controller包下的所有类下的方法。

定义切点以后在通知注解中直接使用requestServer方法名就可以了

使用@Before再切点前执行

@Before("requestServer()")
    public void doBefore(JoinPoint joinPoint) {
        ServletRequestAttributes attributes = (ServletRequestAttributes)
    RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
    
        LOGGER.info("===============================Start========================");
        LOGGER.info("IP : {}", request.getRemoteAddr());
        LOGGER.info("URL : {}", request.getRequestURL().toString());
        LOGGER.info("HTTP Method : {}", request.getMethod());
        LOGGER.info("Class Method : {}.{}", joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName());
    }

在进入Controller方法前，打印出调用方IP、请求URL、HTTP请求类型、调用的方法名

使用@Around打印进入控制层的入参

@Around("requestServer()")
    public Object doAround(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
        long start = System.currentTimeMillis();
        Object result = proceedingJoinPoint.proceed();
        LOGGER.info("Request Params : {}", getRequestParams(proceedingJoinPoint));
        LOGGER.info("Result : {}", result);
        LOGGER.info("Time Cost : {} ms", System.currentTimeMillis() - start);
    
        return result;
    }

打印了入参、结果以及耗时

getRquestParams方法

private Map<String, Object> getRequestParams(ProceedingJoinPoint proceedingJoinPoint) {
         Map<String, Object> requestParams = new HashMap<>();
    
          //参数名
         String[] paramNames = ((MethodSignature)proceedingJoinPoint.getSignature()).getParameterNames();
         //参数值
         Object[] paramValues = proceedingJoinPoint.getArgs();
    
         for (int i = 0; i < paramNames.length; i++) {
             Object value = paramValues[i];
    
             //如果是文件对象
             if (value instanceof MultipartFile) {
                 MultipartFile file = (MultipartFile) value;
                 value = file.getOriginalFilename(); //获取文件名
             }
    
             requestParams.put(paramNames[i], value);
         }
    
         return requestParams;
     }

通过 @PathVariable以及@RequestParam注解传递的参数无法打印出参数名，因此需要手动拼接一下参数名，同时对文件对象进行了特殊处理，只需获取文件名即可

@After方法调用后执行

@After("requestServer()")
    public void doAfter(JoinPoint joinPoint) {
        LOGGER.info("===============================End========================");
    }

没有业务逻辑只是打印了End

完整切面代码

高并发下请求日志切面

写完以后对自己的代码很满意，但是想着可能还有完善的地方就和朋友交流了一下。emmmm

![format_png][]

果然还有继续优化的地方 每个信息都打印一行，在高并发请求下确实会出现请求之间打印日志串行的问题，因为测试阶段请求数量较少没有出现串行的情况，果然生产环境才是第一发展力，能够遇到更多bug，写更健壮的代码 解决日志串行的问题只要将多行打印信息合并为一行就可以了，因此构造一个对象

RequestInfo.java

@Data
    public class RequestInfo {
        private String ip;
        private String url;
        private String httpMethod;
        private String classMethod;
        private Object requestParams;
        private Object result;
        private Long timeCost;
    }
    复制代码
    
    
    环绕通知方法体
    
    
    @Around("requestServer()")
    public Object doAround(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
        long start = System.currentTimeMillis();
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
        Object result = proceedingJoinPoint.proceed();
        RequestInfo requestInfo = new RequestInfo();
                requestInfo.setIp(request.getRemoteAddr());
        requestInfo.setUrl(request.getRequestURL().toString());
        requestInfo.setHttpMethod(request.getMethod());
        requestInfo.setClassMethod(String.format("%s.%s", proceedingJoinPoint.getSignature().getDeclaringTypeName(),
                proceedingJoinPoint.getSignature().getName()));
        requestInfo.setRequestParams(getRequestParamsByProceedingJoinPoint(proceedingJoinPoint));
        requestInfo.setResult(result);
        requestInfo.setTimeCost(System.currentTimeMillis() - start);
        LOGGER.info("Request Info : {}", JSON.toJSONString(requestInfo));
    
        return result;
    }

将url、http request这些信息组装成RequestInfo对象，再序列化打印对象  
 打印**序列化**对象结果而不是直接打印对象是因为序列化有更直观、更清晰，同时可以借助在线解析工具对结果进行解析

![format_png 1][]

是不是还不错  
在解决高并发下请求串行问题的同时添加了对**异常请求信息的打印**，通过使用 @AfterThrowing注解对抛出异常的方法进行处理

RequestErrorInfo.java

@Data
    public class RequestErrorInfo {
        private String ip;
        private String url;
        private String httpMethod;
        private String classMethod;
        private Object requestParams;
        private RuntimeException exception;
    }

异常通知环绕体

@AfterThrowing(pointcut = "requestServer()", throwing = "e")
    public void doAfterThrow(JoinPoint joinPoint, RuntimeException e) {
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
        RequestErrorInfo requestErrorInfo = new RequestErrorInfo();
        requestErrorInfo.setIp(request.getRemoteAddr());
        requestErrorInfo.setUrl(request.getRequestURL().toString());
        requestErrorInfo.setHttpMethod(request.getMethod());
        requestErrorInfo.setClassMethod(String.format("%s.%s", joinPoint.getSignature().getDeclaringTypeName(),
                joinPoint.getSignature().getName()));
        requestErrorInfo.setRequestParams(getRequestParamsByJoinPoint(joinPoint));
        requestErrorInfo.setException(e);
        LOGGER.info("Error Request Info : {}", JSON.toJSONString(requestErrorInfo));
    }

对于异常，耗时是没有意义的，因此不统计耗时，而是添加了异常的打印

最后放一下完整日志请求切面代码：

@Component
    @Aspect
    public class RequestLogAspect {
        private final static Logger LOGGER = LoggerFactory.getLogger(RequestLogAspect.class);
    
        @Pointcut("execution(* your_package.controller..*(..))")
        public void requestServer() {
        }
    
        @Around("requestServer()")
        public Object doAround(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
            long start = System.currentTimeMillis();
            ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
            HttpServletRequest request = attributes.getRequest();
            Object result = proceedingJoinPoint.proceed();
            RequestInfo requestInfo = new RequestInfo();
                    requestInfo.setIp(request.getRemoteAddr());
            requestInfo.setUrl(request.getRequestURL().toString());
            requestInfo.setHttpMethod(request.getMethod());
            requestInfo.setClassMethod(String.format("%s.%s", proceedingJoinPoint.getSignature().getDeclaringTypeName(),
                    proceedingJoinPoint.getSignature().getName()));
            requestInfo.setRequestParams(getRequestParamsByProceedingJoinPoint(proceedingJoinPoint));
            requestInfo.setResult(result);
            requestInfo.setTimeCost(System.currentTimeMillis() - start);
            LOGGER.info("Request Info : {}", JSON.toJSONString(requestInfo));
    
            return result;
        }
    
    
        @AfterThrowing(pointcut = "requestServer()", throwing = "e")
        public void doAfterThrow(JoinPoint joinPoint, RuntimeException e) {
            ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
            HttpServletRequest request = attributes.getRequest();
            RequestErrorInfo requestErrorInfo = new RequestErrorInfo();
            requestErrorInfo.setIp(request.getRemoteAddr());
            requestErrorInfo.setUrl(request.getRequestURL().toString());
            requestErrorInfo.setHttpMethod(request.getMethod());
            requestErrorInfo.setClassMethod(String.format("%s.%s", joinPoint.getSignature().getDeclaringTypeName(),
                    joinPoint.getSignature().getName()));
            requestErrorInfo.setRequestParams(getRequestParamsByJoinPoint(joinPoint));
            requestErrorInfo.setException(e);
            LOGGER.info("Error Request Info : {}", JSON.toJSONString(requestErrorInfo));
        }
    
        /**
         * 获取入参
         * @param proceedingJoinPoint
         *
         * @return
         * */
        private Map<String, Object> getRequestParamsByProceedingJoinPoint(ProceedingJoinPoint proceedingJoinPoint) {
            //参数名
            String[] paramNames = ((MethodSignature)proceedingJoinPoint.getSignature()).getParameterNames();
            //参数值
            Object[] paramValues = proceedingJoinPoint.getArgs();
    
            return buildRequestParam(paramNames, paramValues);
        }
    
        private Map<String, Object> getRequestParamsByJoinPoint(JoinPoint joinPoint) {
            //参数名
            String[] paramNames = ((MethodSignature)joinPoint.getSignature()).getParameterNames();
            //参数值
            Object[] paramValues = joinPoint.getArgs();
    
            return buildRequestParam(paramNames, paramValues);
        }
    
        private Map<String, Object> buildRequestParam(String[] paramNames, Object[] paramValues) {
            Map<String, Object> requestParams = new HashMap<>();
            for (int i = 0; i < paramNames.length; i++) {
                Object value = paramValues[i];
    
                //如果是文件对象
                if (value instanceof MultipartFile) {
                    MultipartFile file = (MultipartFile) value;
                    value = file.getOriginalFilename(); //获取文件名
                }
    
                requestParams.put(paramNames[i], value);
            }
    
            return requestParams;
        }
    
        @Data
        public class RequestInfo {
            private String ip;
            private String url;
            private String httpMethod;
            private String classMethod;
            private Object requestParams;
            private Object result;
            private Long timeCost;
        }
    
        @Data
        public class RequestErrorInfo {
            private String ip;
            private String url;
            private String httpMethod;
            private String classMethod;
            private Object requestParams;
            private RuntimeException exception;
        }
    }

赶紧给你们的应用加上吧【如果没加的话】，没有日志的话，总怀疑上层出错，但是却拿不出证据。

--------------------

\-END-

如果看到这里，说明你喜欢这篇文章，请 转发、点赞。同时 标星（置顶）本公众号可以第一时间接受到博文推送。

**推****荐****阅****读**

***1. ***[程序员必备基础：Git 命令全方位学习][Git]

***2. ***[我发现了 GitHub 的彩蛋！][GitHub]

***3.*** [这 7 个 GitHub 项目太吊了！][7 _ GitHub]

***4. ***[Spring Boot+Redis实现接口自动幂等][Spring Boot_Redis]

![format_png 2][]

最近整理一份面试资料**《Java技术栈学习手册》**，覆盖了Java技术、面试题精选、Spring全家桶、Nginx、SSM、微服务、数据库、数据结构、架构等等。

获取方式：点“ **在看**，关注公众号 **Java后端** 并回复 **777** 领取，更多内容陆续奉上。

喜欢文章，点个在看 ![format_png 3][]

[Java]: http://mp.weixin.qq.com/s?__biz=Mzg2MjEwMjI1Mg%3D%3D&chksm=ce0da17bf97a286df119047a25b7de51621fe542816673bb4aa3ebd8ab97b09a86ed7db2e2ee&idx=3&mid=2247489272&scene=21&sn=ce74938072fc73a808d83ccb474db46d#wechat_redirect
[format_png]: /images/20210730/df8223bbc5e1471e8901c2a0e457afca.png
[format_png 1]: /images/20210730/8b0167458eb541499f521c30949785aa.png
[Git]: http://mp.weixin.qq.com/s?__biz=Mzg2MjEwMjI1Mg%3D%3D&chksm=ce0e4fcbf979c6dd7452566628bf25c477bae0364ee1fbc6693df8ed790f0dddc891b9b998df&idx=2&mid=2247497800&scene=21&sn=842ce1191563a95e41819fa1dd7323d4#wechat_redirect
[GitHub]: http://mp.weixin.qq.com/s?__biz=Mzg2MjEwMjI1Mg%3D%3D&chksm=ce0e40e2f979c9f4e877a174e0d1175317b3c4e00cbc85b59dba9e3545fa53a960baf7ea957c&idx=2&mid=2247497569&scene=21&sn=9617dd590f4e7528393bbbf29cad9584#wechat_redirect
[7 _ GitHub]: http://mp.weixin.qq.com/s?__biz=Mzg2MjEwMjI1Mg%3D%3D&chksm=ce0e4018f979c90ede0480ecc64de41f335cfaa906330f1c889b6c320cce337040423d778b97&idx=1&mid=2247497627&scene=21&sn=3b0470971db810caf893e7bd2a49d8ed#wechat_redirect
[Spring Boot_Redis]: http://mp.weixin.qq.com/s?__biz=Mzg2MjEwMjI1Mg%3D%3D&chksm=ce0e517ef979d868e4f33b739a9f02483f91af2c6337b1e8d899c97f6df2556592a85a9d43ad&idx=1&mid=2247493373&scene=21&sn=6953f10125945ad6105d603cf0750d6b#wechat_redirect
[format_png 2]: /images/20210730/dc8afff8cb454d6d9967033abe92a7c8.png
[format_png 3]: /images/20210730/e1925642333e4910bb148fab8f59abe8.png