在項目開發中,日誌系統是必不可少的,用`AOP`在Web的請求做入參和出參的參數列印,同時對異常進行日誌列印,避免重覆的手寫日誌,完整案例見文末源碼。 ...
在項目開發中,日誌系統是必不可少的,用
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
來區別實在每個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框架都是在運行時刻生成代理。
二、項目示例
當然,在使用該案例之前,如果需要瞭解日誌配置相關,可參考 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"