springboot配置aop切面日志打印

一、SpringBoot Aop說明

1. Aop

AOP(Aspect-Oriented Programming，面向切面編程)，它利用一種”橫切”的技術，將那些多個類的共同行為封裝到一個可重用的模塊。便於減少系統的重復代碼，降低模塊之間的耦合度，並有利於未來的可操作性和可維護性。

2. AOP相關概念：

Aspect（切面）：聲明類似於Java中的類聲明，在Aspect中會包含一些Pointcut及相應的Advice。

Joint point（連接點）：表示在程序中明確定義的點。包括方法的調用、對類成員的訪問等。

Pointcut（切入點）：表示一個組Joint point，如方法名、參數類型、返回類型等等。

Advice（通知）：Advice定義了在Pointcut里面定義的程序點具體要做的操作，它通過(before、around、after(return、throw)、finally來區別實在每個Joint point之前、之后還是執行 前后要調用的代碼。

Before：在執行方法前調用Advice，比如請求接口之前的登錄驗證。

Around：在執行方法前后調用Advice，這是最常用的方法。

After：在執行方法后調用Advice，after、return是方法正常返回后調用，after\throw是方法拋出異常后調用。

Finally：方法調用后執行Advice，無論是否拋出異常還是正常返回。

AOP proxy：AOP proxy也是Java對象，是由AOP框架創建，用來完成上述動作，AOP對象通常可以通過JDK dynamic proxy完成，或者使用CGLIb完成。

Weaving：實現上述切面編程的代碼織入，可以在編譯時刻，也可以在運行時刻，Spring和其它大多數Java框架都是在運行時刻生成代理。

二、代碼示例

1. POM引入

<dependencies>
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-web</artifactId>
    </dependency>
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-aop</artifactId>
    </dependency>
    <!-- 分析客戶端信息的工具類-->
    <dependency>
        <groupId>eu.bitwalker</groupId>
        <artifactId>UserAgentUtils</artifactId>
        <version>1.21</version>
    </dependency>
    <!-- lombok -->
    <dependency>
        <groupId>org.projectlombok</groupId>
        <artifactId>lombok</artifactId>
        <scope>1.18.10</scope>
    </dependency>
</dependencies>

2、切面：WebLogAspect代碼

/**
 * 添加aop日志打印
 *
 * @author 馬振全 2020/1/13 14:42
 */
@Aspect
@Component
@Slf4j
public class WebLogAspect {
    /**
     * 進入方法時間戳
     */
    private Long startTime;
    /**
     * 方法結束時間戳(計時)
     */
    private Long endTime;

    public WebLogAspect() {
    }


    /**
     * 定義請求日志切入點，其切入點表達式有多種匹配方式,這里是指定路徑
     */
    @Pointcut("execution(public * com.soyoung.ad.engine.controller.*.*(..))")
    public void webLogPointcut() {
    }

    /**
     * 前置通知：
     * 1. 在執行目標方法之前執行，比如請求接口之前的登錄驗證;
     * 2. 在前置通知中設置請求日志信息，如開始時間，請求參數，注解內容等
     *
     * @param joinPoint
     * @throws Throwable
     */
    @Before("webLogPointcut()")
    public void doBefore(JoinPoint joinPoint) {

        // 接收到請求，記錄請求內容
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
        //獲取請求頭中的User-Agent
        UserAgent userAgent = UserAgent.parseUserAgentString(request.getHeader("User-Agent"));
        //打印請求的內容
        startTime = System.currentTimeMillis();
        log.info("請求開始時間：{}", LocalDateTime.now());
        log.info("請求Url : {}", request.getRequestURL().toString());
        log.info("請求方式 : {}", request.getMethod());
        log.info("請求ip : {}", request.getRemoteAddr());
        log.info("請求方法 : ", joinPoint.getSignature().getDeclaringTypeName() + "." + joinPoint.getSignature().getName());
        log.info("請求參數 : {}", Arrays.toString(joinPoint.getArgs()));
        // 系統信息
        log.info("瀏覽器：{}", userAgent.getBrowser().toString());
        log.info("瀏覽器版本：{}", userAgent.getBrowserVersion());
        log.info("操作系統: {}", userAgent.getOperatingSystem().toString());
    }

    /**
     * 返回通知：
     * 1. 在目標方法正常結束之后執行
     * 1. 在返回通知中補充請求日志信息，如返回時間，方法耗時，返回值，並且保存日志信息
     *
     * @param ret
     * @throws Throwable
     */
    @AfterReturning(returning = "ret", pointcut = "webLogPointcut()")
    public void doAfterReturning(Object ret) throws Throwable {
        endTime = System.currentTimeMillis();
        log.info("請求結束時間：{}", LocalDateTime.now());
        log.info("請求耗時：{}", (endTime - startTime));
        // 處理完請求，返回內容
        log.info("請求返回 : {}", ret);
    }

    /**
     * 異常通知：
     * 1. 在目標方法非正常結束，發生異常或者拋出異常時執行
     * 1. 在異常通知中設置異常信息，並將其保存
     *
     * @param throwable
     */
    @AfterThrowing(value = "webLogPointcut()", throwing = "throwable")
    public void doAfterThrowing(Throwable throwable) {
        // 保存異常日志記錄
        log.error("發生異常時間：{}", LocalDateTime.now());
        log.error("拋出異常：{}", throwable.getMessage());
    }
}

3、@Before和@AfterReturning部分也可使用以下代碼替代

    /**
     * 在執行方法前后調用Advice，這是最常用的方法，相當於@Before和@AfterReturning全部做的事兒
     * @param pjp
     * @return
     * @throws Throwable
     */
    @Around("webLogPointcut()")
    public Object doAround(ProceedingJoinPoint pjp) throws Throwable {
        // 接收到請求，記錄請求內容
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
        //獲取請求頭中的User-Agent
        UserAgent userAgent = UserAgent.parseUserAgentString(request.getHeader("User-Agent"));
        //打印請求的內容
        startTime = System.currentTimeMillis();
        log.info("請求Url : {}" , request.getRequestURL().toString());
        log.info("請求方式 : {}" , request.getMethod());
        log.info("請求ip : {}" , request.getRemoteAddr());
        log.info("請求方法 : " , pjp.getSignature().getDeclaringTypeName() , "." , pjp.getSignature().getName());
        log.info("請求參數 : {}" , Arrays.toString(pjp.getArgs()));
    // 系統信息
        log.info("瀏覽器：{}", userAgent.getBrowser().toString());
        log.info("瀏覽器版本：{}",userAgent.getBrowserVersion());
        log.info("操作系統: {}", userAgent.getOperatingSystem().toString());
        // pjp.proceed()：當我們執行完切面代碼之后，還有繼續處理業務相關的代碼。proceed()方法會繼續執行業務代碼，並且其返回值，就是業務處理完成之后的返回值。
        Object ret = pjp.proceed();
        log.info("請求結束時間："+ LocalDateTime.now());
        log.info("請求耗時：{}" , (System.currentTimeMillis() - startTime));
        // 處理完請求，返回內容
        log.info("請求返回 : " , ret);
        return ret;
    }

4、測試結果

2020-01-13 15:18:21.309 INFO xxx.WebLogAspect : 請求開始時間：2020-01-13T15:18:21.309
2020-01-13 15:18:21.309 INFO xxx.WebLogAspect : 請求Url : http://localhost:8020/api/v1/hourlyStat/findHourlyStatReportList
2020-01-13 15:18:21.320 INFO xxx.WebLogAspect : 請求方式 : POST
2020-01-13 15:18:21.321 INFO xxx.WebLogAspect : 請求ip : 0:0:0:0:0:0:0:1
2020-01-13 15:18:21.322 INFO xxx.WebLogAspect : 請求方法 :
2020-01-13 15:18:21.325 INFO xxx.WebLogAspect : 請求參數 : [HourlyStat{subStrategyId=null}]
2020-01-13 15:18:21.326 INFO xxx.WebLogAspect : 瀏覽器：CHROME
2020-01-13 15:18:21.327 INFO xxx.WebLogAspect : 瀏覽器版本：78.0.3904.108
2020-01-13 15:18:21.333 INFO xxx.WebLogAspect : 操作系統: WINDOWS_10
2020-01-13 15:18:21.403 INFO xxx.WebLogAspect : 請求結束時間：2020-01-13T15:18:21.403
2020-01-13 15:18:21.405 INFO xxx.WebLogAspect : 請求耗時：94
2020-01-13 15:18:21.405 INFO xxx.WebLogAspect : 請求返回 : com.soyoung.ad.engine.common.Result@2f935d03
2020-01-13 15:18:21.492 INFO xxx.WebLogAspect : 請求結束時間：2020-01-13T15:18:21.492
2020-01-13 15:18:21.493 INFO xxx.WebLogAspect : 請求耗時：183
2020-01-13 15:18:21.494 INFO xxx.WebLogAspect : 請求返回 : com.soyoung.ad.engine.common.Result@7199e922
2020-01-13 15:18:42.859 INFO xxx.WebLogAspect : 請求開始時間：2020-01-13T15:18:42.859
2020-01-13 15:18:42.860 INFO xxx.WebLogAspect : 請求Url : http://localhost:8020/api/v1/hourlyStat/findHourlyStatReportList
2020-01-13 15:18:42.860 INFO xxx.WebLogAspect : 請求方式 : POST
2020-01-13 15:18:42.861 INFO xxx.WebLogAspect : 請求ip : 0:0:0:0:0:0:0:1
2020-01-13 15:18:42.861 INFO xxx.WebLogAspect : 請求方法 :
2020-01-13 15:18:42.862 INFO xxx.WebLogAspect : 請求參數 : [HourlyStat{subStrategyId=1003}]
2020-01-13 15:18:42.862 INFO xxx.WebLogAspect : 瀏覽器：CHROME
2020-01-13 15:18:42.863 INFO xxx.WebLogAspect : 瀏覽器版本：78.0.3904.108
2020-01-13 15:18:42.864 INFO xxx.WebLogAspect : 操作系統: WINDOWS_10
2020-01-13 15:18:42.909 INFO xxx.WebLogAspect : 請求結束時間：2020-01-13T15:18:42.909
2020-01-13 15:18:42.910 INFO xxx.WebLogAspect : 請求耗時：50
2020-01-13 15:18:42.910 INFO xxx.WebLogAspect : 請求返回 : com.soyoung.ad.engine.common.Result@7d494cbd