java优雅的打印日志——对controller层方法的进入和结束地方打印日志——直接使用

场景：

看日志是后端常用的操作，但是日志过于多的时候，很难分清日志打印的是不是同一个调用里面的。所以在controller的方法的开始和结尾的地方，打印日志，并且打印入参和出参，这样就能够很好的分析日志的逻辑了。

1、引入依赖

由于每一个controller层的方法都需要打印进入和返回的日志，所以使用AOP的思想可以很好的解决，我们这边使用静态代理AspectJ。

        <dependency>
            <groupId>org.aspectj</groupId>
            <artifactId>aspectjweaver</artifactId>
            <version>1.9.5</version>
        </dependency>

        <!-- https://mvnrepository.com/artifact/com.alibaba/fastjson -->
        <dependency>
            <groupId>com.alibaba</groupId>
            <artifactId>fastjson</artifactId>
            <version>1.2.73</version>
        </dependency>
        <!-- https://mvnrepository.com/artifact/org.apache.commons/commons-lang3 -->
        <dependency>
            <groupId>org.apache.commons</groupId>
            <artifactId>commons-lang3</artifactId>
            <version>3.9</version>
        </dependency>

2、自定义注解

一个自定义的注解：用于描述该接口的作用

/**
 * @author qsm
 * @date 2020/9/3 14:20
 * @description controller层的方法上，给该方法取一个名字。作用是给LogAspect打印进入方法退出方法的日志
 */
@Target({ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
public @interface ControllerMethodTitle {

    String value() default "";
}

3、日志切面代码LogAspect

下面直接给出代码，修改一下Pointcut的路径，便可以直接使用：

package com.xxx.ins.qsm.demo.web.commom.aspact;

import com.alibaba.fastjson.JSON;
import com.alibaba.fastjson.JSONObject;
import lombok.extern.slf4j.Slf4j;
import org.apache.commons.lang3.ObjectUtils;
import org.apache.commons.lang3.StringUtils;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.beans.factory.annotation.Autowired;
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 org.springframework.web.multipart.MultipartFile;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.lang.reflect.Method;
import java.util.Arrays;
import java.util.List;
import java.util.stream.Collectors;
import java.util.stream.Stream;

@Component
@Aspect
@Slf4j
@Order(-98)
public class LogAspect {

    @Autowired
    HttpServletRequest request;
    /**
     * 【注意】 修改为你自己项目中controller层路径
     */
    @Pointcut("execution(public * com.qsm.xxx.xx.xxxx.controller..*.*(..))")
    public void pointcut() {
    }


    @Around("pointcut()")
    public Object handle(ProceedingJoinPoint joinPoint) throws Throwable {
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();

        //请求controller名称，使用@ControllerMethodTitle注解
        String controllerTitle = getControllerMethodTitle(joinPoint);
        //方法路径
        String methodName = joinPoint.getSignature().getDeclaringTypeName() + "." + joinPoint.getSignature().getName();
        //IP地址
        String iP = getIp(request);
        //请求入参
        String requestParam = JSON.toJSONString(Arrays.stream(joinPoint.getArgs())
          .filter(param -> !(param instanceof HttpServletRequest)
                          && !(param instanceof HttpServletResponse)
                          && !(param instanceof MultipartFile)
                          && !(param instanceof MultipartFile[])
          ).collect(Collectors.toList()));
          
        log.info("\n    [Controller start], {}, methodName->{}, IP->{}, requestParam->{},", controllerTitle, methodName, iP, requestParam);

        long begin = System.currentTimeMillis();
        Object result = joinPoint.proceed();

        log.info("\n    [Controller end], {}, 耗时->{}ms, result->{}", controllerTitle, System.currentTimeMillis() - begin, JSONObject.toJSONString(result));
        return result;
    }

    /**
     * 获取Controller的方法名
     */

    private String getControllerMethodTitle(ProceedingJoinPoint joinPoint) {
        Method[] methods = joinPoint.getSignature().getDeclaringType().getMethods();
        for (Method method : methods) {
            if (StringUtils.equalsIgnoreCase(method.getName(), joinPoint.getSignature().getName())) {
                ControllerMethodTitle annotation = method.getAnnotation(ControllerMethodTitle.class);
                if (ObjectUtils.isNotEmpty(annotation)) {
                    return annotation.value();
                }
            }
        }
        return "该Controller的方法使用未使用注解@ControllerMethodTitle，请使用该注解说明方法作用";
    }

    /**
     * 获取目标主机的ip
     *
     * @param request
     * @return
     */
    private String getIp(HttpServletRequest request) {
        List<String> ipHeadList = Stream.of("X-Forwarded-For", "Proxy-Client-IP", "WL-Proxy-Client-IP", "HTTP_CLIENT_IP", "X-Real-IP").collect(Collectors.toList());
        for (String ipHead : ipHeadList) {
            if (checkIP(request.getHeader(ipHead))) {
                return request.getHeader(ipHead).split(",")[0];
            }
        }
        return "0:0:0:0:0:0:0:1".equals(request.getRemoteAddr()) ? "127.0.0.1" : request.getRemoteAddr();
    }

    /**
     * 检查ip存在
     */
    private boolean checkIP(String ip) {
        return !(null == ip || 0 == ip.length() || "unknown".equalsIgnoreCase(ip));
    }


}

4、使用方法

使用方法非常的简单，直接在controller的方法上面直接使用自定义的注解@ControllerMethodTitle即可。

@RestController
@RequestMapping("/log")
@Slf4j
public class LogController {

    @PostMapping("/qsm")
    @ControllerMethodTitle("我是一个可爱的测试获取qsm的接口")
    public Qsm2 http(@RequestBody @Valid Qsm2 qsm2, HttpServletRequest request) {
        log.info("\n    [处理中], 程序正在处理请求逻辑");
        return qsm2;
    }
}

打印的日志

2020-09-07 19:25:14.773  INFO 13276 --- [nio-8080-exec-3] c.j.i.q.d.web.commom.aspact.LogAspect    : 
    [开始], 我是一个可爱的测试获取qsm的接口, methodName->com.xxx.ins.qsm.demo.web.controller.LogController.http, IP->127.0.0.1, reqParam->[{"name":"demoData","status":"123"}],
2020-09-07 19:25:14.783  INFO 13276 --- [nio-8080-exec-3] c.j.i.q.d.web.controller.LogController   : 
    [处理中], 程序正在处理请求逻辑
2020-09-07 19:25:14.784  INFO 13276 --- [nio-8080-exec-3] c.j.i.q.d.web.commom.aspact.LogAspect    : 
    [结束], 我是一个可爱的测试获取qsm的接口, 耗时->10ms, result->{"name":"demoData","status":"123"} 

到此，非常优雅简单的打印请求和返回的日志就好了，还是非常有用的。喜欢就点个赞吧~~~

---

【续】

程序中有时候使用了swagger，而对于controller里面的接口，会使用@ApiOperation注解，该注解本身就有描述该方法，所以若使用了该注解，就不需要使用我们自定义的注解@ControllerMethodTitle显得有点冗余。但是，若没有使用swagger，依然推荐使用我们的自定义注解。

使用swagger时的操作：

1、引入依赖

        <dependency>
            <groupId>io.springfox</groupId>
            <artifactId>springfox-swagger2</artifactId>
            <version>2.6.0</version>
        </dependency>
        <dependency>
            <groupId>io.springfox</groupId>
            <artifactId>springfox-swagger-ui</artifactId>
            <version>2.6.0</version>
        </dependency>

2、替换日志切面代码LogAspect类中的getControllerMethodTitle方法为

    /**
     * 获取Controller的方法名
     * 可以使用我们自定义的@ControllerMethodTitle。若使用了swagger，就优先使用swagger的@ApiOperation的value
     */
    private String getControllerMethodTitle(ProceedingJoinPoint joinPoint) {
        Method[] methods = joinPoint.getSignature().getDeclaringType().getMethods();
        for (Method method : methods) {
            if (StringUtils.equalsIgnoreCase(method.getName(), joinPoint.getSignature().getName())) {
                ApiOperation apiOperation = method.getAnnotation(ApiOperation.class);
                ControllerMethodTitle controllerMethodTitle = method.getAnnotation(ControllerMethodTitle.class);
                if (ObjectUtils.isNotEmpty(apiOperation) && StringUtils.isNotBlank(apiOperation.value())) {
                    return apiOperation.value();
                }
                if (ObjectUtils.isNotEmpty(controllerMethodTitle)) {
                    return controllerMethodTitle.value();
                }
            }
        }
        return "该Controller的方法使用未使用注解@ControllerMethodTitle，请使用该注解说明方法作用";
    }

3、使用，在controller方法中使用

    @GetMapping("/dataBinder")
    @ApiOperation(value = "我是一个可爱的测试获取dataBinder的接口")
    public Qsm2 dataBinder(DataBinder dataBinder, HttpServletRequest request) {
        log.info("\n    [处理中], 程序正在处理请求逻辑2222{},{},{}", env, env2, env3);
        return null;
    }

【完】

正在去BAT的路上修行