Spring Boot中使用AOP統一處理Web請求日志
AOP為Aspect Oriented Programming的縮寫,意為:面向切面編程,通過預編譯方式和運行期動態代理實現程序功能的統一維護的一種技術。AOP是Spring框架中的一個重要內容,它通過對既有程序定義一個切入點,然后在其前后切入不同的執行內容,比如常見的有:打開數據庫連接/關閉數據庫連接、打開事務/關閉事務、記錄日志等。基于AOP不會破壞原來程序邏輯,因此它可以很好的對業務邏輯的各個部分進行隔離,從而使得業務邏輯各部分之間的耦合度降低,提高程序的可重用性,同時提高了開發的效率。
下面主要講兩個內容,一個是如何在Spring Boot中引入Aop功能,二是如何使用Aop做切面去統一處理Web請求的日志。
以下所有操作基于 chapter4-2-2工程 進行。
準備工作
因為需要對web請求做切面來記錄日志,所以先引入web模塊,并創建一個簡單的hello請求的處理。
- pom.xml 中引入web模塊
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
</dependency>
- 實現一個簡單請求處理:通過傳入name參數,返回“hello xxx”的功能。
@RestController
public class HelloController {
@RequestMapping(value = "/hello", method = RequestMethod.GET)
@ResponseBody
public String hello(@RequestParam String name) {
return "Hello " + name;
}
}
下面,我們可以對上面的/hello請求,進行切面日志記錄。
引入AOP依賴
在Spring Boot中引入AOP就跟引入其他模塊一樣,非常簡單,只需要在 pom.xml 中加入如下依賴:
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-aop</artifactId>
</dependency>
在完成了引入AOP依賴包后,一般來說并不需要去做其他配置。也許在Spring中使用過注解配置方式的人會問是否需要在程序主類中增加 @EnableAspectJAutoProxy 來啟用,實際并不需要。
可以看下面關于AOP的默認配置屬性,其中 spring.aop.auto 屬性默認是開啟的,也就是說只要引入了AOP依賴后,默認已經增加了 @EnableAspectJAutoProxy 。
# AOP
spring.aop.auto=true # Add @EnableAspectJAutoProxy.
spring.aop.proxy-target-class=false # Whether subclass-based (CGLIB) proxies are to be created (true) as
opposed to standard Java interface-based proxies (false).
而當我們需要使用CGLIB來實現AOP的時候,需要配置 spring.aop.proxy-target-class=true ,不然默認使用的是標準Java的實現。
實現Web層的日志切面
實現AOP的切面主要有以下幾個要素:
- 使用 @Aspect 注解將一個java類定義為切面類
- 使用 @Pointcut 定義一個切入點,可以是一個規則表達式,比如下例中某個package下的所有函數,也可以是一個注解等。
- 根據需要在切入點不同位置的切入內容
- 使用 @Before 在切入點開始處切入內容
- 使用 @After 在切入點結尾處切入內容
- 使用 @AfterReturning 在切入點return內容之后切入內容(可以用來對處理返回值做一些加工處理)
- 使用 @Around 在切入點前后切入內容,并自己控制何時執行切入點自身的內容
- 使用 @AfterThrowing 用來處理當切入內容部分拋出異常之后的處理邏輯
@Aspect
@Component
public class WebLogAspect {
private Logger logger = Logger.getLogger(getClass());
@Pointcut("execution(public * com.didispace.web..*.*(..))")
public void webLog(){}
@Before("webLog()")
public void doBefore(JoinPoint joinPoint) throws Throwable {
// 接收到請求,記錄請求內容
ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
HttpServletRequest request = attributes.getRequest();
// 記錄下請求內容
logger.info("URL : " + request.getRequestURL().toString());
logger.info("HTTP_METHOD : " + request.getMethod());
logger.info("IP : " + request.getRemoteAddr());
logger.info("CLASS_METHOD : " + joinPoint.getSignature().getDeclaringTypeName() + "." + joinPoint.getSignature().getName());
logger.info("ARGS : " + Arrays.toString(joinPoint.getArgs()));
}
@AfterReturning(returning = "ret", pointcut = "webLog()")
public void doAfterReturning(Object ret) throws Throwable {
// 處理完請求,返回內容
logger.info("RESPONSE : " + ret);
}
}
可以看上面的例子,通過 @Pointcut 定義的切入點為 com.didispace.web 包下的所有函數(對web層所有請求處理做切入點),然后通過 @Before 實現,對請求內容的日志記錄(本文只是說明過程,可以根據需要調整內容),最后通過 @AfterReturning 記錄請求返回的對象。
通過運行程序并訪問: http://localhost:8080/hello?name=didi ,可以獲得下面的日志輸出
2016-05-19 13:42:13,156 INFO WebLogAspect:41 - URL : http://localhost:8080/hello
2016-05-19 13:42:13,156 INFO WebLogAspect:42 - HTTP_METHOD : http://localhost:8080/hello
2016-05-19 13:42:13,157 INFO WebLogAspect:43 - IP : 0:0:0:0:0:0:0:1
2016-05-19 13:42:13,160 INFO WebLogAspect:44 - CLASS_METHOD : com.didispace.web.HelloController.hello
2016-05-19 13:42:13,160 INFO WebLogAspect:45 - ARGS : [didi]
2016-05-19 13:42:13,170 INFO WebLogAspect:52 - RESPONSE:Hello didi
優化:AOP切面中的同步問題
在WebLogAspect切面中,分別通過doBefore和doAfterReturning兩個獨立函數實現了切點頭部和切點返回后執行的內容,若我們想統計請求的處理時間,就需要在doBefore處記錄時間,并在doAfterReturning處通過當前時間與開始處記錄的時間計算得到請求處理的消耗時間。
那么我們是否可以在WebLogAspect切面中定義一個成員變量來給doBefore和doAfterReturning一起訪問呢?是否會有同步問題呢?
的確,直接在這里定義基本類型會有同步問題,所以我們可以引入ThreadLocal對象,像下面這樣進行記錄:
@Aspect
@Component
public class WebLogAspect {
private Logger logger = Logger.getLogger(getClass());
ThreadLocal<Long> startTime = new ThreadLocal<>();
@Pointcut("execution(public * com.didispace.web..*.*(..))")
public void webLog(){}
@Before("webLog()")
public void doBefore(JoinPoint joinPoint) throws Throwable {
startTime.set(System.currentTimeMillis());
// 省略日志記錄內容
}
@AfterReturning(returning = "ret", pointcut = "webLog()")
public void doAfterReturning(Object ret) throws Throwable {
// 處理完請求,返回內容
logger.info("RESPONSE : " + ret);
logger.info("SPEND TIME : " + (System.currentTimeMillis() - startTime.get()));
}
}
優化:AOP切面的優先級
由于通過AOP實現,程序得到了很好的解耦,但是也會帶來一些問題,比如:我們可能會對Web層做多個切面,校驗用戶,校驗頭信息等等,這個時候經常會碰到切面的處理順序問題。
所以,我們需要定義每個切面的優先級,我們需要 @Order(i) 注解來標識切面的優先級。 i的值越小,優先級越高 。假設我們還有一個切面是 CheckNameAspect 用來校驗name必須為didi,我們為其設置 @Order(10) ,而上文中WebLogAspect設置為 @Order(5) ,所以WebLogAspect有更高的優先級,這個時候執行順序是這樣的:
- 在 @Before 中優先執行 @Order(5) 的內容,再執行 @Order(10) 的內容
- 在 @After 和 @AfterReturning 中優先執行 @Order(10) 的內容,再執行 @Order(5) 的內容
所以我們可以這樣子總結:
- 在切入點前的操作,按order的值由小到大執行
- 在切入點后的操作,按order的值由大到小執行
來自: http://blog.didispace.com/springbootaoplog/