spring中使用aop記錄日誌
在之前一系列的文章中都是提供了全部的程式碼,在之後的文章中就提供核心的程式碼進行講解。有什麼問題大家可以給我留言或者加我QQ,進行諮詢。
AOP為Aspect Oriented Programming的縮寫,意為:面向切面程式設計,通過預編譯方式和執行期動態代理實現程式功能的統一維護的一種技術。AOP是Spring框架中的一個重要內容,它通過對既有程式定義一個切入點,然後在其前後切入不同的執行內容,比如常見的有:開啟資料庫連線/關閉資料庫連線、開啟事務/關閉事務、記錄日誌等。基於AOP不會破壞原來程式邏輯,因此它可以很好的對業務邏輯的各個部分進行隔離,從而使得業務邏輯各部分之間的耦合度降低,提高程式的可重用性,同時提高了開發的效率。
本文就是要通過AOP技術統一處理web請求的日誌。
準備工作
因為需要對web請求做切面來記錄日誌,所以先引入web模組,並建立一個簡單的hello請求的處理。
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
</dependency>
實現一個簡單請求處理:
@RestController
publicclass
@RequestMapping("/hello")
public String hello(String name,int state){
return"name "+name+"---"+state;
}
}
這時候我們編寫一個啟動類啟動執行程式訪問:
引入AOP依賴
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-aop</
</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用來處理當切入內容部分丟擲異常之後的處理邏輯
package com.kfit.config.aop.log;
import java.util.Arrays;
import java.util.Enumeration;
import javax.servlet.http.HttpServletRequest;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.AfterReturning;
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.core.annotation.Order;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;
/**
* 實現Web層的日誌切面
* @author Angel(QQ:412887952)
* @version v.0.1
*/
@Aspect
@Component
@Order(-5)
public class WebLogAspect {
private Logger logger = LoggerFactory.getLogger(this.getClass());
/**
* 定義一個切入點.
* 解釋下:
*
* ~ 第一個 * 代表任意修飾符及任意返回值.
* ~ 第二個 * 任意包名
* ~ 第三個 * 代表任意方法.
* ~ 第四個 * 定義在web包或者子包
* ~ 第五個 * 任意方法
* ~ .. 匹配任意數量的引數.
*/
@Pointcut("execution(public * com.kfit.*.web..*.*(..))")
publicvoid webLog(){}
@Before("webLog()")
publicvoid doBefore(JoinPoint joinPoint){
// 接收到請求,記錄請求內容
logger.info("WebLogAspect.doBefore()");
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()));
//獲取所有引數方法一:
Enumeration<String> enu=request.getParameterNames();
while(enu.hasMoreElements()){
String paraName=(String)enu.nextElement();
System.out.println(paraName+": "+request.getParameter(paraName));
}
}
@AfterReturning("webLog()")
publicvoid doAfterReturning(JoinPoint joinPoint){
// 處理完請求,返回內容
logger.info("WebLogAspect.doAfterReturning()");
}
}
整個程式碼比較不好理解地方就是切點表示式,已經在註釋中詳細說明了,這裡不再過多的介紹。編碼中需要根據您自己的包命名規範進行修改下。
: WebLogAspect.doBefore()
: URL : http://127.0.0.1:8080/hello
: HTTP_METHOD : GET
: IP : 127.0.0.1
: CLASS_METHOD : com.kfit.demo.web.HelloController.hello
: ARGS : [林峰, 1]
name: 林峰
state: 1
: WebLogAspect.doAfterReturning()
: 耗時(毫秒) : 1
優化:AOP切面中的同步問題
在WebLogAspect切面中,分別通過doBefore和doAfterReturning兩個獨立函式實現了切點頭部和切點返回後執行的內容,若我們想統計請求的處理時間,就需要在doBefore處記錄時間,並在doAfterReturning處通過當前時間與開始處記錄的時間計算得到請求處理的消耗時間。
那麼我們是否可以在WebLogAspect切面中定義一個成員變數來給doBefore和doAfterReturning一起訪問呢?是否會有同步問題呢?
的確,直接在這裡定義基本型別會有同步問題,所以我們可以引入ThreadLocal物件,像下面這樣進行記錄改造程式碼為如下:
package com.kfit.config.aop.log;
import java.util.Arrays;
import java.util.Enumeration;
import javax.servlet.http.HttpServletRequest;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.AfterReturning;
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.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;
/**
* 實現Web層的日誌切面
* @author Angel(QQ:412887952)
* @version v.0.1
*/
@Aspect
@Component
public class WebLogAspect {
private Logger logger = LoggerFactory.getLogger(this.getClass());
ThreadLocal<Long> startTime = new ThreadLocal<Long>();
/**
* 定義一個切入點.
* 解釋下:
*
* ~ 第一個 * 代表任意修飾符及任意返回值.
* ~ 第二個 * 任意包名
* ~ 第三個 * 代表任意方法.
* ~ 第四個 * 定義在web包或者子包
* ~ 第五個 * 任意方法
* ~ .. 匹配任意數量的引數.
*/
@Pointcut("execution(public * com.kfit.*.web..*.*(..))")
publicvoid webLog(){}
@Before("webLog()")
publicvoid doBefore(JoinPoint joinPoint){
startTime.set(System.currentTimeMillis());
// 接收到請求,記錄請求內容
logger.info("WebLogAspect.doBefore()");
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()));
//獲取所有引數方法一:
Enumeration<String> enu=request.getParameterNames();
while(enu.hasMoreElements()){
String paraName=(String)enu.nextElement();
System.out.println(paraName+": "+request.getParameter(paraName));
}
}
@AfterReturning("webLog()")
publicvoid doAfterReturning(JoinPoint joinPoint){
// 處理完請求,返回內容
logger.info("WebLogAspect.doAfterReturning()");
logger.info("耗時(毫秒) : " + (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的值由大到小執行