Spring Boot 使用AOP进行Web访问日志记录

AOP（Aspect Oriented Programming），即面向切面编程，可以说是OOP（Object Oriented Programming，面向对象编程）的补充和完善。OOP引入封装、继承、多态等概念来建立一种对象层次结构，用于模拟公共行为的一个集合。不过OOP允许开发者定义纵向的关系，但并不适合定义横向的关系，例如日志功能。日志代码往往横向地散布在所有对象层次中，而与它对应的对象的核心功能毫无关系对于其他类型的代码，如安全性、异常处理和透明的持续性也都是如此，这种散布在各处的无关的代码被称为横切（cross cutting），在OOP设计中，它导致了大量代码的重复，而不利于各个模块的重用。

AOP技术恰恰相反，它利用一种称为"横切"的技术，剖解开封装的对象内部，并将那些影响了多个类的公共行为封装到一个可重用模块，并将其命名为"Aspect"，即切面。所谓"切面"，简单说就是那些与业务无关，却为业务模块所共同调用的逻辑或责任封装起来，便于减少系统的重复代码，降低模块之间的耦合度，并有利于未来的可操作性和可维护性。

使用"横切"技术，AOP把软件系统分为两个部分：核心关注点和横切关注点。业务处理的主要流程是核心关注点，与之关系不大的部分是横切关注点。横切关注点的一个特点是，他们经常发生在核心关注点的多处，而各处基本相似，比如权限认证、日志、事物。AOP的作用在于分离系统中的各种关注点，将核心关注点和横切关注点分离开来。

下面从代码方面介绍了如何定义AOP 进行WEB访问日志记录：

通过观看https://my.oschina.net/sdlvzg/blog/1154281创建项目，再执行以下操作

加载所需要JAR

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

创建日志实体Bean

package org.lvgang;

import java.sql.Timestamp;

/**
*
* @author Administrator
*
*/
public class LoggerEntity{

//编号
private Long id;
//客户端请求ip
private String clientIp;
//客户端请求路径
private String uri;
//终端请求方式,普通请求,ajax请求
private String type;
//请求方式method,post,get等
private String method;
//请求的类及方法
private String classMethod;
//请求参数内容,json
private String paramData;
//请求接口唯一session标识
private String sessionId;
//请求时间
private Timestamp time;
//接口返回时间
private String returnTime;
//接口返回数据json
private String returnData;
//请求时httpStatusCode代码，如：200,400,404等
private String httpStatusCode;
//请求耗时秒单位
private int timeConsuming;
//异常描述
private String exceptionMessage;
//请求开始时间
private long startTime;
//请求结束时间
private long endTime;

public String getExceptionMessage() {
return exceptionMessage;
}

public void setExceptionMessage(String exceptionMessage) {
this.exceptionMessage = exceptionMessage;
}

public String getClassMethod() {
return classMethod;
}

public void setClassMethod(String classMethod) {
this.classMethod = classMethod;
}

public long getStartTime() {
return startTime;
}

public void setStartTime(long startTime) {
this.startTime = startTime;
}

public long getEndTime() {
return endTime;
}

public void setEndTime(long endTime) {
this.endTime = endTime;
}

public Long getId() {
return id;
}

public void setId(Long id) {
this.id = id;
}

public String getClientIp() {
return clientIp;
}

public void setClientIp(String clientIp) {
this.clientIp = clientIp;
}

public String getUri() {
return uri;
}

public void setUri(String uri) {
this.uri = uri;
}

public String getType() {
return type;
}

public void setType(String type) {
this.type = type;
}

pub
3ff0
lic String getMethod() {
return method;
}

public void setMethod(String method) {
this.method = method;
}

public String getParamData() {
return paramData;
}

public void setParamData(String paramData) {
this.paramData = paramData;
}

public String getSessionId() {
return sessionId;
}

public void setSessionId(String sessionId) {
this.sessionId = sessionId;
}

public Timestamp getTime() {
return time;
}

public void setTime(Timestamp time) {
this.time = time;
}

public String getReturnTime() {
return returnTime;
}

public void setReturnTime(String returnTime) {
this.returnTime = returnTime;
}

public String getReturnData() {
return returnData;
}

public void setReturnData(String returnData) {
this.returnData = returnData;
}

public String getHttpStatusCode() {
return httpStatusCode;
}

public void setHttpStatusCode(String httpStatusCode) {
this.httpStatusCode = httpStatusCode;
}

public int getTimeConsuming() {
return timeConsuming;
}

public void setTimeConsuming(int timeConsuming) {
this.timeConsuming = timeConsuming;
}

@Override
public String toString() {
return "LoggerEntity [id=" + id + ", clientIp=" + clientIp + ", uri=" + uri + ", type=" + type + ", method="
+ method + ", classMethod=" + classMethod + ", paramData=" + paramData + ", sessionId=" + sessionId
+ ", time=" + time + ", returnTime=" + returnTime + ", returnData=" + returnData + ", httpStatusCode="
+ httpStatusCode + ", timeConsuming=" + timeConsuming + ", exceptionMessage=" + exceptionMessage + ", startTime=" + startTime + ", endTime=" + endTime + "]";
}

}

编写日志工具类

package org.lvgang;

import javax.servlet.http.HttpServletRequest;
/**
*
* @author Administrator
*
*/
public class LoggerUtils {
public static final String LOGGER_RETURN = "_logger_return";

private LoggerUtils() {}

/**
* 获取客户端ip地址
* @param request
* @return
*/
public static String getCliectIp(HttpServletRequest request)
{
String ip = request.getHeader("x-forwarded-for");
if (ip == null || ip.trim() == "" || "unknown".equalsIgnoreCase(ip)) {
ip = request.getHeader("Proxy-Client-IP");
}
if (ip == null || ip.trim() == "" || "unknown".equalsIgnoreCase(ip)) {
ip = request.getHeader("WL-Proxy-Client-IP");
}
if (ip == null || ip.trim() == "" || "unknown".equalsIgnoreCase(ip)) {
ip = request.getRemoteAddr();
}

// 多个路由时，取第一个非unknown的ip
final String[] arr = ip.split(",");
for (final String str : arr) {
if (!"unknown".equalsIgnoreCase(str)) {
ip = str;
break;
}
}
return ip;
}

/**
* 判断是否为ajax请求
* @param request
* @return
*/
public static String getRequestType(HttpServletRequest request) {
return request.getHeader("X-Requested-With");
}
}

编写日志AOP处理类

package org.lvgang;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.AfterReturning;
import org.aspectj.lang.annotation.AfterThrowing;
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;

import com.alibaba.fastjson.JSON;
import com.alibaba.fastjson.serializer.SerializerFeature;

/**
*
* @author Administrator
*
*/
@Aspect
@Component

public class WebLogAspect {
private final static Logger logger = LoggerFactory.getLogger(WebLogAspect.class);

//	ThreadLocal是什么
//	　　早在JDK 1.2的版本中就提供Java.lang.ThreadLocal，ThreadLocal为解决多线程程序的并发问题提供了一种新的思路。使用这个工具类可以很简洁地编写出优美的多线程程序。
//	　　当使用ThreadLocal维护变量时，ThreadLocal为每个使用该变量的线程提供独立的变量副本，所以每一个线程都可以独立地改变自己的副本，而不会影响其它线程所对应的副本。
//	　　从线程的角度看，目标变量就象是线程的本地变量，这也是类名中“Local”所要表达的意思。
//	　　所以，在Java中编写线程局部变量的代码相对来说要笨拙一些，因此造成线程局部变量没有在Java开发者中得到很好的普及。
//	ThreadLocal的接口方法
//	ThreadLocal类接口很简单，只有4个方法，我们先来了解一下：
//	void set(Object value)设置当前线程的线程局部变量的值。
//	public Object get()该方法返回当前线程所对应的线程局部变量。
//	public void remove()将当前线程局部变量的值删除，目的是为了减少内存的占用，该方法是JDK 5.0新增的方法。需要指出的是，当线程结束后，对应该线程的局部变量将自动被垃圾回收，所以显式调用该方法清除线程的局部变量并不是必须的操作，但它可以加快内存回收的速度。
//	protected Object initialValue()返回该线程局部变量的初始值，该方法是一个protected的方法，显然是为了让子类覆盖而设计的。这个方法是一个延迟调用方法，在线程第1次调用get()或set(Object)时才执行，并且仅执行1次。ThreadLocal中的缺省实现直接返回一个null。
//	　　值得一提的是，在JDK5.0中，ThreadLocal已经支持泛型，该类的类名已经变为ThreadLocal<T>。API方法也相应进行了调整，新版本的API方法分别是void set(T value)、T get()以及T initialValue()。
ThreadLocal<LoggerEntity> loggerEntityThreadLocal = new ThreadLocal<LoggerEntity>();

//请求开始时间标识
//    使用@Aspect注解将一个java类定义为切面类
//    使用@Pointcut定义一个切入点，可以是一个规则表达式，比如下例中某个package下的所有函数，也可以是一个注解等。
//    根据需要在切入点不同位置的切入内容
//    使用@Before在切入点开始处切入内容
//    使用@After在切入点结尾处切入内容
//    使用@AfterReturning在切入点return内容之后切入内容（可以用来对处理返回值做一些加工处理）
//    使用@Around在切入点前后切入内容，并自己控制何时执行切入点自身的内容
//    使用@AfterThrowing用来处理当切入内容部分抛出异常之后的处理逻辑

/**
* 定义一个切入点.
* 解释下：
*
* ~ 第一个 * 代表任意修饰符及任意返回值.
* ~ 第二个 * 任意包名
* ~ 第三个 * 代表任意方法.
* ~ 第四个 * 定义在web包或者子包
* ~ 第五个 * 任意方法
* ~ .. 匹配任意数量的参数.
*/
@Pointcut("execution(public * org.lvgang.controller..*.*(..))")
public void webLog(){}

/**
* 前置通知，方法调用前被调用
* @param joinPoint
*/
@Before("webLog()")
public void doBefore(JoinPoint joinPoint){

// 接收到请求，记录请求内容
logger.info("WebLogAspect.doBefore()");
ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
HttpServletRequest request = attributes.getRequest();
//创建日志实体
LoggerEntity logger = new LoggerEntity();
//请求开始时间
logger.setStartTime(System.currentTimeMillis());
//获取请求sessionId
String sessionId = request.getRequestedSessionId();
//请求路径
String url = request.getRequestURI();
//获取请求参数信息
String paramData = JSON.toJSONString(request.getParameterMap(),SerializerFeature.DisableCircularReferenceDetect,SerializerFeature.WriteMapNullValue);
//设置客户端ip
logger.setClientIp(LoggerUtils.getCliectIp(request));
//设置请求方法
logger.setMethod(request.getMethod());
//设置请求类型（json|普通请求）
logger.setType(LoggerUtils.getRequestType(request));
//设置请求地址
logger.setUri(url);
//设置sessionId
logger.setSessionId(sessionId);
//请求的类及名称
logger.setClassMethod(joinPoint.getSignature().getDeclaringTypeName() + "." + joinPoint.getSignature().getName());
//设置请求参数内容json字符串
logger.setParamData(paramData);
loggerEntityThreadLocal.set(logger);

}

/**
* 后置返回通知
* 这里需要注意的是:
*      如果参数中的第一个参数为JoinPoint，则第二个参数为返回值的信息
*      如果参数中的第一个参数不为JoinPoint，则第一个参数为returning中对应的参数
* returning 限定了只有目标方法返回值与通知方法相应参数类型时才能执行后置返回通知，否则不执行，对于returning对应的通知方法参数为Object类型将匹配任何目标返回值
* @param joinPoint
* @param keys
*/
@AfterReturning(value = "webLog()",returning = "returnData")
public void  doAfterReturning(JoinPoint joinPoint,Object returnData){
// 处理完请求，返回内容
logger.info("WebLogAspect.doAfterReturning()");
logger.info("RETURN DATA:"+ returnData);

ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
//        HttpServletRequest request = attributes.getRequest();
HttpServletResponse response = attributes.getResponse();

//获取请求错误码
int status = response.getStatus();
//获取本次请求日志实体
LoggerEntity loggerEntity = loggerEntityThreadLocal.get();
//请求结束时间
loggerEntity.setEndTime(System.currentTimeMillis());
//设置请求时间差
loggerEntity.setTimeConsuming(Integer.valueOf((loggerEntity.getEndTime() - loggerEntity.getStartTime())+""));
//设置返回时间
loggerEntity.setReturnTime(loggerEntity.getEndTime() + "");
//设置返回错误码
loggerEntity.setHttpStatusCode(status+"");
//设置返回值
loggerEntity.setReturnData(JSON.toJSONString(returnData,SerializerFeature.DisableCircularReferenceDetect,SerializerFeature.WriteMapNullValue));
//执行将日志写入数据库
logger.info(JSON.toJSONString(loggerEntity));

}

/**
* 后置异常通知
*  定义一个名字，该名字用于匹配通知实现方法的一个参数名，当目标方法抛出异常返回后，将把目标方法抛出的异常传给通知方法；
*  throwing 限定了只有目标方法抛出的异常与通知方法相应参数异常类型时才能执行后置异常通知，否则不执行，
*      对于throwing对应的通知方法参数为Throwable类型将匹配任何异常。
* @param joinPoint
* @param exception
*/
@AfterThrowing(value = "webLog()",throwing = "exception")
public void doAfterThrowingAdvice(JoinPoint joinPoint,Throwable exception){
//目标方法名：
LoggerEntity loggerEntity = loggerEntityThreadLocal.get();
loggerEntity.setExceptionMessage(exception.getMessage());
logger.info(JSON.toJSONString(loggerEntity));
//         if(exception instanceof NullPointerException){
//             System.out.println("发生了空指针异常!!!!!");
//         }
}

/**
* 后置最终通知（目标方法只要执行完了就会执行后置通知方法）
* @param joinPoint
*/
//     @After(value = "webLog()")
//     public void doAfterAdvice(JoinPoint joinPoint){
//         System.out.println("后置通知执行了!!!!");
//     }

/**
* 环绕通知：
*   环绕通知非常强大，可以决定目标方法是否执行，什么时候执行，执行时是否需要替换方法参数，执行完毕是否需要替换返回值。
*   环绕通知第一个参数必须是org.aspectj.lang.ProceedingJoinPoint类型
*/
//     @Around(value = "webLog()")
//     public Object doAroundAdvice(ProceedingJoinPoint proceedingJoinPoint){
//         System.out.println("环绕通知的目标方法名："+proceedingJoinPoint.getSignature().getName());
//         try {//obj之前可以写目标方法执行前的逻辑
//             Object obj = proceedingJoinPoint.proceed();//调用执行目标方法
//             return obj;
//         } catch (Throwable throwable) {
//             throwable.printStackTrace();
//         }
//         return null;
//     }

}

编写测试Controller(在原有的类中增加方法)

package org.lvgang.controller;

import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;

/**
* Hello测试类
* @author Administrator
*
*/
@RestController   // 等价于@Controller+@RequstMapping
public class HelloController {
@RequestMapping("/hello")
public String hello(){
return "Hello world test!";
}

@RequestMapping("/hello2")
public String hello2(String name){
return "Hello "+name+" !";
}
}

通过新编写的Main方法启动项目，然后通过浏览器访问http://localhost:8080/hello?name=lvgang联接，控制台输出以下信息表示成功

{"classMethod":"org.lvgang.controller.HelloController.hello2",
"clientIp":"0:0:0:0:0:0:0:1",
"endTime":1503295904763,
"httpStatusCode":"200",
"method":"GET",
"paramData":"{\"name\":[\"lvgang\"]}",
"returnData":"\"Hello lvgang !\"",
"returnTime":"1503295904763",
startTime":1503295904748,
"timeConsuming":15,
"uri":"/hello2"}