SpringBoot 配置 AOP 打印日志
在項目開發中，日志系統是必不可少的，用
AOP在Web的請求做入參和出參的參數打印，同時對異常進行日志打印，避免重復的手寫日志，完整案例見文末源碼。
一、Spring AOP
AOP(Aspect-Oriented Programming，面向切面編程)，它利用一種"橫切"的技術，將那些多個類的共同行為封裝到一個可重用的模塊。便於減少系統的重復代碼，降低模塊之間的耦合度，並有利於未來的可操作性和可維護性。
AOP中有以下概念：
Aspect（切面）：聲明類似於Java中的類聲明，在Aspect中會包含一些Pointcut及相應的Advice。Joint point（連接點）：表示在程序中明確定義的點。包括方法的調用、對類成員的訪問等。Pointcut（切入點）：表示一個組Joint point，如方法名、參數類型、返回類型等等。Advice（通知）：Advice定義了在Pointcut里面定義的程序點具體要做的操作，它通過(before、around、after(return、throw)、finally來區別實在每個Jointpoint之前、之后還是執行 前后要調用的代碼。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框架都是在運行時刻生成代理。
二、項目示例
當然，在使用該案例之前，如果需要了解日志配置相關，可參考 SpringBoot 異步輸出 Logback 日志， 本文就不再概述了。
2.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.20</version> </dependency> <!-- lombok --> <dependency> <groupId>org.projectlombok</groupId> <artifactId>lombok</artifactId> <scope>1.8.4</scope> </dependency> </dependencies> 2.2 Controller 切面：WebLogAspect
@Aspect @Component @Slf4j public class WebLogAspect { /** * 進入方法時間戳 */ private Long startTime; /** * 方法結束時間戳(計時) */ private Long endTime; public WebLogAspect() { } /** * 定義請求日志切入點，其切入點表達式有多種匹配方式,這里是指定路徑 */ @Pointcut("execution(public * cn.van.log.aop.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()); } } 2.3 編寫測試
@RestController @RequestMapping("/log") public class LogbackController { /** * 測試正常請求 * @param msg * @return */ @GetMapping("/{msg}") public String getMsg(@PathVariable String msg) { return "request msg : " + msg; } /** * 測試拋異常 * @return */ @GetMapping("/test") public String getException(){ // 故意造出一個異常 Integer.parseInt("abc123"); return "success"; } } 2.4 @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; } 三、 測試
3.1 請求入口LogbackController.java
@RestController @RequestMapping("/log") public class LogbackController { /** * 測試正常請求 * @param msg * @return */ @GetMapping("/normal/{msg}") public String getMsg(@PathVariable String msg) { return msg; } /** * 測試拋異常 * @return */ @GetMapping("/exception/{msg}") public String getException(@PathVariable String msg){ // 故意造出一個異常 Integer.parseInt("abc123"); return msg; } } 3.2 測試正常請求
打開瀏覽器，訪問http://localhost:8082/log/normal/hello
日志打印如下：
[2019-02-24 22:37:50.050] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-1] [65] [INFO ] 請求開始時間：2019-02-24T22:37:50.892
[2019-02-24 22:37:50.050] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-1] [66] [INFO ] 請求Url : http://localhost:8082/log/normal/hello
[2019-02-24 22:37:50.050] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-1] [67] [INFO ] 請求方式 : GET
[2019-02-24 22:37:50.050] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-1] [68] [INFO ] 請求ip : 0:0:0:0:0:0:0:1
[2019-02-24 22:37:50.050] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-1] [69] [INFO ] 請求方法 :
[2019-02-24 22:37:50.050] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-1] [70] [INFO ] 請求參數 : [hello]
[2019-02-24 22:37:50.050] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-1] [72] [INFO ] 瀏覽器：CHROME
[2019-02-24 22:37:50.050] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-1] [73] [INFO ] 瀏覽器版本：76.0.3809.100
[2019-02-24 22:37:50.050] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-1] [74] [INFO ] 操作系統: MAC_OS_X
[2019-02-24 22:37:50.050] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-1] [88] [INFO ] 請求結束時間：2019-02-24T22:37:50.901
[2019-02-24 22:37:50.050] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-1] [89] [INFO ] 請求耗時：14
[2019-02-24 22:37:50.050] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-1] [91] [INFO ] 請求返回 : hello
3.3 測試異常情況
訪問：http://localhost:8082/log/exception/hello
[2019-02-24 22:39:57.057] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-9] [65] [INFO ] 請求開始時間：2019-02-24T22:39:57.728
[2019-02-24 22:39:57.057] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-9] [66] [INFO ] 請求Url : http://localhost:8082/log/exception/hello
[2019-02-24 22:39:57.057] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-9] [67] [INFO ] 請求方式 : GET
[2019-02-24 22:39:57.057] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-9] [68] [INFO ] 請求ip : 0:0:0:0:0:0:0:1
[2019-02-24 22:39:57.057] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-9] [69] [INFO ] 請求方法 :
[2019-02-24 22:39:57.057] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-9] [70] [INFO ] 請求參數 : [hello]
[2019-02-24 22:39:57.057] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-9] [72] [INFO ] 瀏覽器：CHROME
[2019-02-24 22:39:57.057] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-9] [73] [INFO ] 瀏覽器版本：76.0.3809.100
[2019-02-24 22:39:57.057] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-9] [74] [INFO ] 操作系統: MAC_OS_X
[2019-02-24 22:39:57.057] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-9] [104] [ERROR] 發生異常時間：2019-02-24T22:39:57.731
[2019-02-24 22:39:57.057] [cn.van.log.aop.aspect.WebLogAspect] [http-nio-8082-exec-9] [105] [ERROR] 拋出異常：For input string: "abc123"
[2019-02-24 22:39:57.057] [org.apache.juli.logging.DirectJDKLog] [http-nio-8082-exec-9] [175] [ERROR] Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is java.lang.NumberFormatException: For input string: "abc123"] with root cause
java.lang.NumberFormatException: For input string: "abc123"