spring boot 使用AOP统一处理Web请求日志

AOP为Aspect Oriented Programming的缩写，意为：面向切面编程，通过预编译方式和运行期动态代理实现程序功能的统一维护的一种技术。AOP是Spring框架中的一个重要内容，它通过对既有程序定义一个切入点，然后在其前后切入不同的执行内容，比如常见的有：打开数据库连接/关闭数据库连接、打开事务/关闭事务、记录日志等。基于AOP不会破坏原来程序逻辑，因此它可以很好的对业务逻辑的各个部分进行隔离，从而使得业务逻辑各部分之间的耦合度降低，提高程序的可重用性，同时提高了开发的效率。

       本文就是要通过AOP技术统一处理web请求的日志。

准备工作

  因为需要对web请求做切面来记录日志，所以先引入web模块，并创建一个简单的hello请求的处理。

1 2 3 4

< dependency >        < groupId >org.springframework.boot</ groupId >        < artifactId >spring-boot-starter-web</ artifactId > </ dependency >

实现一个简单请求处理：

1 2 3 4 5 6 7 8

@RestController publicclass HelloController {           @RequestMapping ( "/hello" )      public  String hello(String name, int  state){         return "name " +name+ "---" +state;      } }

这时候我们编写一个启动类启动运行程序访问：

http://127.0.0.1:8080/hello?name=xxx&state=1  就能看到页面返回的信息了，但是现在还是不能进行拦截的。

引入AOP依赖

1 2 3 4

< 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用来处理当切入内容部分抛出异常之后的处理逻辑

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71

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层的日志切面     * @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()" );       }        }

整个代码比较不好理解地方就是切点表达式，已经在注释中详细说明了，这里不再过多的介绍。编码中需要根据您自己的包命名规范进行修改下。

这时候运行程序访问 http://127.0.0.1:8080/hello?name=xxx&state=1  就可以看到控制台的打印信息了。

1 2 3 4 5 6 7 8 9 10

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 : [xxx,  1 ] name: xxx state:  1 : WebLogAspect.doAfterReturning() : 耗时（毫秒） :  1

优化：AOP切面中的同步问题

       在WebLogAspect切面中，分别通过doBefore和doAfterReturning两个独立函数实现了切点头部和切点返回后执行的内容，若我们想统计请求的处理时间，就需要在doBefore处记录时间，并在doAfterReturning处通过当前时间与开始处记录的时间计算得到请求处理的消耗时间。

 

       那么我们是否可以在WebLogAspect切面中定义一个成员变量来给doBefore和doAfterReturning一起访问呢？是否会有同步问题呢？

 

       的确，直接在这里定义基本类型会有同步问题，所以我们可以引入ThreadLocal对象，像下面这样进行记录改造代码为如下：

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74

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层的日志切面   *    * @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的值由大到小执行

 在实际中order值可以设置为负值，确保是第一个进行执行的。