1. Home
  2. /系列文章
  3. /Java Spring Boot開發Restful API
  4. /Spring Boot EP 12：透過AOP將重複的程式整合，並在特定時機執行
spring boot slf4j logback listener filter json aop http get scheduling tasks

Spring Boot EP 12：透過AOP將重複的程式整合，並在特定時機執行

Java Spring Boot開發Restful API / 2022-02-04 / Jovepater

Aspect Oriented Programming, AOP

在撰寫程時，很多時候都會有一些重複發生的需求，例如紀錄日誌、發送訊息等，一般而言會在任何有需求的地方撰寫程式，但這樣對後續的維護並不友善，而且容易改A壞B，或是掛萬漏一。既然這些重複的需求都在做差不多的事情，也在差不多的時候要執行，那不如就將他們抽離出來。AOP就是將這些重複的事情整合起來在，並在規定的時間執行。

AOP要先定義一個Pointcut (切入點)，姑且把Pointcut視作某一段程式的代言人，該段程式可以是一整個類別或是一個函數，根據Pointcut有幾個重要的程式執行時間，如下：

  • Before：在Pointcut被執行之前。
  • AfterReturning：在Pointcut正常完成之後。
  • AfterThrowing：在Pointcut出現錯誤(Exception)之後。
  • After：無論Pointcut有無正常完成都要執行。

實作AOP

步驟1：在”STOCKMARKET/src/main/java/stockmarket/jovepater/com/stockmarket/”建立一個名為Aspects的資料夾，並新增一個LoggingAspect.java檔案。

步驟2：實作AOP，如下：

package stockmarket.jovepater.com.stockmarket.Aspects;

import java.util.Objects;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.After;
import org.aspectj.lang.annotation.AfterReturning;
import org.aspectj.lang.annotation.AfterThrowing;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;

@Aspect
@Component
// 可以有多的AOP，並透過@Order()來控制執行順序
@Order(0)
public class LoggingAspect {

    // 切入點，定義Controller下的所有程式都被涵蓋在內
    @Pointcut("execution(public * stockmarket.jovepater.com.stockmarket.Controllers..*.*(..))")
    public void LoggingAspectPointcut() {
        // 基本上不用特別實作
    }

    // 宣告時間戳記使用的變數，紀錄Controller的執行起訖
    Long longTimeStampStart, longTimeStampEnd;

    // ＠Before表示在Controller之前運作
    @Before("LoggingAspectPointcut()")
    public void BeforePointcut(JoinPoint joinPoint) {
        // 紀錄Controller啟動時間
        longTimeStampStart = System.currentTimeMillis();
    }

    // 帶入JoinPoint表示被執行的那個Pointcut程式類別
    // @AfterReturning表示在Controller正常完成之後運作
    @AfterReturning("LoggingAspectPointcut()")
    public void AfterReturningOfPointcut(JoinPoint joinPoint) {
        // 在日誌輸出Controller正常執行完成的資訊
        Logger(LoggerFactory.getLogger(joinPoint.getTarget().getClass()), "API Finished Normally.");
    }

    // @AfterThrowing表示Controller發生錯誤時要做的事情
    @AfterThrowing(value = "LoggingAspectPointcut()", throwing = "exception")
    public void AfterThrowingOfPointcut(JoinPoint joinPoint, Exception exception) {
        Logger myLogger = LoggerFactory.getLogger(joinPoint.getTarget().getClass());

        // 在日誌輸出Exception資訊
        myLogger.error("API Finished by Exception: {}", exception.getMessage());
    }

    // @After表示Controller無論有沒有正常結束都要做的事情
    @After("LoggingAspectPointcut()")
    public void AfterPointcut(JoinPoint joinPoint) {
        // 紀錄Controller結束時間
        longTimeStampEnd = System.currentTimeMillis();

        // 起訖時間相減取得該Controller的執行時間
        Long longTimeDiff = longTimeStampEnd - longTimeStampStart;

        // 在日誌輸出Controller執行時間
        Logger(LoggerFactory.getLogger(joinPoint.getTarget().getClass()),
                "Time used: " + Objects.toString(longTimeDiff) + " ms");

        // 在日誌輸出Request相關資訊
        Logger(LoggerFactory.getLogger(joinPoint.getTarget().getClass()), joinPoint);
    }

    // 注入HttpServletRequest以便取得Request資訊
    @Autowired
    private HttpServletRequest request;

    // 注入HttpServletResponse以便取得Response資訊
    @Autowired
    private HttpServletResponse response;

    private void Logger(Logger myLogger, JoinPoint joinPoint) {
        String protocol = Objects.toString(request.getProtocol(), "");
        String method = request.getMethod();
        String scheme = request.getScheme();
        String uri = request.getRequestURI();
        String agent = request.getHeader("user-agent");
        String remoteaddr = request.getRemoteAddr();
        int remoteaport = request.getRemotePort();
        String localaddr = request.getLocalAddr();
        int localport = request.getLocalPort();

        String sessionid = request.getSession().getId();

        String classname = joinPoint.getTarget().getClass().getName();
        String classmethod = joinPoint.getSignature().getName();

        String strMessage = "\r\nController Logging Message:\r\n";
        strMessage += String.format("%s\r\n", "---------------------------------------------------");
        strMessage += String.format("  Session ID: %s\r\n", sessionid);
        strMessage += String.format("    Protocol: %s\r\n", protocol);
        strMessage += String.format("      Method: %s\r\n", method);
        strMessage += String.format("         Url: %s://%s:%d%s\r\n", scheme, localaddr, localport, uri);
        strMessage += String.format("       Agent: %s\r\n", agent);
        strMessage += String.format("      Remote: %s:%d\r\n", remoteaddr, remoteaport);
        strMessage += String.format("  Class Name: %s\r\n", classname);
        strMessage += String.format("Class Method: %s", classmethod);

        myLogger.info(strMessage);
    }

    private void Logger(Logger myLogger, String message) {
        myLogger.info(message);
    }
}

步驟3：當任何一個Restful API被呼叫，並且沒有發出任何錯誤，AOP會統一處理日誌與執行時間的計算。

日誌訊息如下：

2022-02-04 19:37:34.757 INFO  [http-nio-8080-exec-1] stockmarket.jovepater.com.stockmarket.Filters.HttpTransatcionLoggingFilter: Request: GET /api/stocks , Msg: Auth OK.
2022-02-04 19:37:34.757 INFO  [http-nio-8080-exec-1] stockmarket.jovepater.com.stockmarket.Filters.HttpTransatcionLoggingFilter: Request: GET /api/stocks , Msg: Content Type Checked.
2022-02-04 19:37:34.757 INFO  [http-nio-8080-exec-1] stockmarket.jovepater.com.stockmarket.Filters.HttpTransatcionLoggingFilter: Request: GET /api/stocks , from: 127.0.0.1
# Controller正常結束，觸發AfterReturning將資訊顯示在日誌中
2022-02-04 19:37:34.916 INFO  [http-nio-8080-exec-1] stockmarket.jovepater.com.stockmarket.Controllers.StockController: API Finished Normally.
# 顯示這個Controller從啟動到執行完成所花費的時間
2022-02-04 19:37:34.916 INFO  [http-nio-8080-exec-1] stockmarket.jovepater.com.stockmarket.Controllers.StockController: Time used: 130 ms
# 將Controller的Request資訊顯示在日誌中
2022-02-04 19:37:34.947 INFO  [http-nio-8080-exec-1] stockmarket.jovepater.com.stockmarket.Controllers.StockController: 
Controller Logging Message:
---------------------------------------------------
  Session ID: 6071ECEA2AB595F42F7283F5B80C65C8
    Protocol: HTTP/1.1
      Method: GET
         Url: http://127.0.0.1:8080/api/stocks
       Agent: PostmanRuntime/7.28.4
      Remote: 127.0.0.1:61349
  Class Name: stockmarket.jovepater.com.stockmarket.Controllers.StockController
Class Method: getAllMarkets
2022-02-04 19:37:35.019 INFO  [http-nio-8080-exec-1] stockmarket.jovepater.com.stockmarket.Filters.HttpTransatcionLoggingFilter: Response: 200 /api/stocks

步驟4：在此，在Hello這個API加入會出現錯誤的程式碼(int x = 5 / 0;)。

@RestController
public class HelloController {

    @GetMapping("hello")
    public RspBody Hello() {
        // 宣告SLF4J的Logger日誌
        Logger myLogger = LoggerFactory.getLogger(HelloController.class);
        // 紀錄各種等級的事件
        myLogger.trace("This is Hello API.");
        myLogger.debug("This is Hello API.");
        myLogger.info("This is Hello API.");
        myLogger.warn("This is Hello API.");
        myLogger.error("This is Hello API.");

        // 不允許除以0，程式會出現錯誤
        int x = 5 / 0;

        return new RspBody("0000", "Success", "Hello World");
    }
}

步驟5：執行上述Restful API會出現錯誤，AOP也會透過”AfterThrowing”執行相對應的動作。

日誌訊息如下：

2022-02-04 19:42:09.494 INFO  [http-nio-8080-exec-3] stockmarket.jovepater.com.stockmarket.Filters.HttpTransatcionLoggingFilter: Request: GET /api/hello , Msg: Auth OK.
2022-02-04 19:42:09.494 INFO  [http-nio-8080-exec-3] stockmarket.jovepater.com.stockmarket.Filters.HttpTransatcionLoggingFilter: Request: GET /api/hello , Msg: Content Type Checked.
2022-02-04 19:42:09.494 INFO  [http-nio-8080-exec-3] stockmarket.jovepater.com.stockmarket.Filters.HttpTransatcionLoggingFilter: Request: GET /api/hello , from: 127.0.0.1
2022-02-04 19:42:09.500 INFO  [http-nio-8080-exec-3] stockmarket.jovepater.com.stockmarket.Controllers.HelloController: This is Hello API.
2022-02-04 19:42:09.500 WARN  [http-nio-8080-exec-3] stockmarket.jovepater.com.stockmarket.Controllers.HelloController: This is Hello API.
2022-02-04 19:42:09.500 ERROR [http-nio-8080-exec-3] stockmarket.jovepater.com.stockmarket.Controllers.HelloController: This is Hello API.
# 觸發AfterThrowing，並將Exception資訊透過顯示在日誌中
2022-02-04 19:42:09.500 ERROR [http-nio-8080-exec-3] stockmarket.jovepater.com.stockmarket.Controllers.HelloController: API Finished by Exception: / by zero
# 顯示這個Controller從啟動到因錯誤停止所花費的時間
2022-02-04 19:42:09.500 INFO  [http-nio-8080-exec-3] stockmarket.jovepater.com.stockmarket.Controllers.HelloController: Time used: 5 ms
2022-02-04 19:42:09.501 INFO  [http-nio-8080-exec-3] stockmarket.jovepater.com.stockmarket.Controllers.HelloController: 
Controller Logging Message:
---------------------------------------------------
  Session ID: 6071ECEA2AB595F42F7283F5B80C65C8
    Protocol: HTTP/1.1
      Method: GET
         Url: http://127.0.0.1:8080/api/hello
       Agent: PostmanRuntime/7.28.4
      Remote: 127.0.0.1:61357
  Class Name: stockmarket.jovepater.com.stockmarket.Controllers.HelloController
Class Method: Hello
# 仍會發出原本的Exception資訊，AOP並不會取代原本的機制
2022-02-04 19:42:09.509 ERROR [http-nio-8080-exec-3] org.apache.catalina.core.ContainerBase.[Tomcat].[localhost].[/api].[dispatcherServlet]: Servlet.service() for servlet [dispatcherServlet] in context with path [/api] threw exception [Request processing failed; nested exception is java.lang.ArithmeticException: / by zero] with root cause
java.lang.ArithmeticException: / by zero
        at stockmarket.jovepater.com.stockmarket.Controllers.HelloController.Hello(HelloController.java:23)
        at stockmarket.jovepater.com.stockmarket.Controllers.HelloController$$FastClassBySpringCGLIB$$cb294f00.invoke(<generated>)
        at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
        at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:783)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
...
...
...

~ END ~

< Spring Boot EP 11：實作Filter處理Request與ResponseSpring Boot EP 13：Exception的全域/區域與客製化處理 >
Post Views: 126

, ,

Related posts

Latest posts

Search