SpringCloud使用AOP统一处理Web请求日志实现步骤

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0"
         xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>
    <artifactId>springms-aop-weblog</artifactId>
    <version>1.0-SNAPSHOT</version>
    <packaging>jar</packaging>
    <parent>
        <groupId>com.springms.cloud</groupId>
        <artifactId>springms-spring-cloud</artifactId>
        <version>1.0-SNAPSHOT</version>
    </parent>
    <dependencies>
        <!-- 访问数据库模块 -->
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-data-jpa</artifactId>
        </dependency>
        <!-- web模块 -->
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
        </dependency>
        <!-- h2数据库模块 -->
        <dependency>
            <groupId>com.h2database</groupId>
            <artifactId>h2</artifactId>
            <scope>runtime</scope>
        </dependency>
        <!-- 支持Apache Solr搜索平台，包括spring-data-solr -->
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-data-solr</artifactId>
        </dependency>
    </dependencies>
</project>

server:
  port: 8350
spring:
  application:
    name: springms-aop-weblog  #全部小写
  jpa:
    generate-ddl: false
    show-sql: true
    hibernate:
      ddl-auto: none
  datasource:
    platform: h2
    schema: classpath:schema.sql
    data: classpath:data.sql

drop table user if exists;
CREATE TABLE USER(
    id BIGINT GENERATED by default as identity,
    username VARCHAR(40),
    name VARCHAR(20),
    age int(3),
    balance DECIMAL(10, 2),
    PRIMARY KEY(id)
);

INSERT into user (id, username, name, age, balance) values (1, 'user1', '张三', 20, 100.00);
INSERT into user (id, username, name, age, balance) values (2, 'user2', '李四', 22, 100.00);
INSERT into user (id, username, name, age, balance) values (3, 'user3', '王五', 24, 100.00);
INSERT into user (id, username, name, age, balance) values (4, 'user4', '赵六', 26, 100.00);
INSERT into user (id, username, name, age, balance) values (5, 'user5', '李逵', 27, 100.00);
INSERT into user (id, username, name, age, balance) values (6, 'user6', '张远', 10, 100.00);
INSERT into user (id, username, name, age, balance) values (7, 'user7', '迪拜', 60, 100.00);
INSERT into user (id, username, name, age, balance) values (8, 'user8', '哈士奇', 40, 100.00);
INSERT into user (id, username, name, age, balance) values (9, 'user9', '关羽', 30, 100.00);

package com.springms.cloud.repository;
import com.springms.cloud.entity.User;
import org.springframework.data.jpa.repository.JpaRepository;
import org.springframework.stereotype.Repository;
@Repository
public interface UserRepository extends JpaRepository<User, Long> {
}

package com.springms.cloud.entity;
import java.math.BigDecimal;
import javax.persistence.Column;
import javax.persistence.Entity;
import javax.persistence.GeneratedValue;
import javax.persistence.GenerationType;
import javax.persistence.Id;
@Entity
public class User {
  @Id
  @GeneratedValue(strategy = GenerationType.AUTO)
  private Long id;
  @Column
  private String username;
  @Column
  private String name;
  @Column
  private Short age;
  @Column
  private BigDecimal balance;
  public Long getId() {
    return this.id;
  }
  public void setId(Long id) {
    this.id = id;
  }
  public String getUsername() {
    return this.username;
  }
  public void setUsername(String username) {
    this.username = username;
  }
  public String getName() {
    return this.name;
  }
  public void setName(String name) {
    this.name = name;
  }
  public Short getAge() {
    return this.age;
  }
  public void setAge(Short age) {
    this.age = age;
  }
  public BigDecimal getBalance() {
    return this.balance;
  }
  public void setBalance(BigDecimal balance) {
    this.balance = balance;
  }
}

package com.springms.cloud.aop;
import org.apache.log4j.Logger;
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.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;
import javax.servlet.http.HttpServletRequest;
import java.util.Arrays;
/****************************************************************************************
 实现AOP的切面主要有以下几个要素：
 使用@Aspect注解将一个java类定义为切面类
 使用@Pointcut定义一个切入点，可以是一个规则表达式，比如下例中某个package下的所有函数，也可以是一个注解等。
 根据需要在切入点不同位置的切入内容
 使用@Before在切入点开始处切入内容
 使用@After在切入点结尾处切入内容
 使用@AfterReturning在切入点return内容之后切入内容（可以用来对处理返回值做一些加工处理）
 使用@Around在切入点前后切入内容，并自己控制何时执行切入点自身的内容
 使用@AfterThrowing用来处理当切入内容部分抛出异常之后的处理逻辑
 使用@Order(i)注解来标识切面的优先级。i的值越小，优先级越高
 ****************************************************************************************/
/****************************************************************************************
 执行日志顺序：
 2017-10-19 20:22:35.810  INFO 9014 --- [nio-8350-exec-1] WebLogHeadAspect    : (Order(1))************** (doBefore) URL : http://localhost:8350/simple/1
 2017-10-19 20:22:35.810  INFO 9014 --- [nio-8350-exec-1] WebLogHeadAspect    : (Order(1))************** (doBefore) HTTP_METHOD : GET
 2017-10-19 20:22:35.810  INFO 9014 --- [nio-8350-exec-1] WebLogHeadAspect    : (Order(1))************** (doBefore) IP : 127.0.0.1
 2017-10-19 20:22:35.811  INFO 9014 --- [nio-8350-exec-1] WebLogHeadAspect    : (Order(1))************** (doBefore) CLASS_METHOD : com.springms.cloud.controller.SimpleProviderUserAopWebLogController.findById
 2017-10-19 20:22:35.811  INFO 9014 --- [nio-8350-exec-1] WebLogHeadAspect    : (Order(1))************** (doBefore) ARGS : [1]
 2017-10-19 20:22:35.811  INFO 9014 --- [nio-8350-exec-1] com.springms.cloud.aop.WebLogFiveAspect        : (Order(5))============== (doBefore) URL : http://localhost:8350/simple/1
 2017-10-19 20:22:35.811  INFO 9014 --- [nio-8350-exec-1] com.springms.cloud.aop.WebLogFiveAspect        : (Order(5))============== (doBefore) HTTP_METHOD : GET
 2017-10-19 20:22:35.811  INFO 9014 --- [nio-8350-exec-1] com.springms.cloud.aop.WebLogFiveAspect        : (Order(5))============== (doBefore) IP : 127.0.0.1
 2017-10-19 20:22:35.811  INFO 9014 --- [nio-8350-exec-1] com.springms.cloud.aop.WebLogFiveAspect        : (Order(5))============== (doBefore) CLASS_METHOD : com.springms.cloud.controller.SimpleProviderUserAopWebLogController.findById
 2017-10-19 20:22:35.811  INFO 9014 --- [nio-8350-exec-1] com.springms.cloud.aop.WebLogFiveAspect        : (Order(5))============== (doBefore) ARGS : [1]
 Hibernate: select user0_.id as id1_0_0_, user0_.age as age2_0_0_, user0_.balance as balance3_0_0_, user0_.name as name4_0_0_, user0_.username as username5_0_0_ from user user0_ where user0_.id=?
 2017-10-19 20:22:35.853  INFO 9014 --- [nio-8350-exec-1] com.springms.cloud.aop.WebLogFiveAspect        : (Order(5))============== (doAfterReturning) RESPONSE : User@1249202
 2017-10-19 20:22:35.853  INFO 9014 --- [nio-8350-exec-1] com.springms.cloud.aop.WebLogFiveAspect        : (Order(5))============== (doAfterReturning) SPEND TIME : 42
 2017-10-19 20:22:35.853  INFO 9014 --- [nio-8350-exec-1] WebLogHeadAspect    : (Order(1))************** (doAfterReturning) RESPONSE : User@1249202
 2017-10-19 20:22:35.853  INFO 9014 --- [nio-8350-exec-1] WebLogHeadAspect    : (Order(1))************** (doAfterReturning) SPEND TIME : 43
 总结：doBefore 方法先从优先级到低优先级依次执行完，然后 doAfterReturning 方法从低优先级到高优先级依次执行完；也就是进入从高到低，出来从低到高；
 ****************************************************************************************/
/**
 * Web层日志切面。
 *
 * @author hmilyylimh
 *
 * @version 0.0.1
 *
 * @date 2017/10/19
 *
 */
@Aspect
@Order(1)
@Component
public class WebLogHeadAspect {
    // private static final org.slf4j.Logger logger = LoggerFactory.getLogger(PreZuulFilter.class);
    private Logger logger = Logger.getLogger(getClass());
    ThreadLocal<Long> startTime = new ThreadLocal<>();
    private static final String PRE_TAG = "(Order(1))************** ";
    @Pointcut("execution(public * com.springms.cloud.controller..*.*(..))")
    public void webLog(){}
    @Before("webLog()")
    public void doBefore(JoinPoint joinPoint) throws Throwable {
        startTime.set(System.currentTimeMillis());
        // 接收到请求，记录请求内容
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
        // 记录下请求内容
        logger.info(PRE_TAG + "(doBefore) URL : " + request.getRequestURL().toString());
        logger.info(PRE_TAG + "(doBefore) HTTP_METHOD : " + request.getMethod());
        logger.info(PRE_TAG + "(doBefore) IP : " + request.getRemoteAddr());
        logger.info(PRE_TAG + "(doBefore) CLASS_METHOD : " + joinPoint.getSignature().getDeclaringTypeName() + "." + joinPoint.getSignature().getName());
        logger.info(PRE_TAG + "(doBefore) ARGS : " + Arrays.toString(joinPoint.getArgs()));
    }
    @AfterReturning(returning = "ret", pointcut = "webLog()")
    public void doAfterReturning(Object ret) throws Throwable {
        // 处理完请求，返回内容
        logger.info(PRE_TAG + "(doAfterReturning) RESPONSE : " + ret);
        logger.info(PRE_TAG + "(doAfterReturning) SPEND TIME : " + (System.currentTimeMillis() - startTime.get()));
    }
}

package com.springms.cloud.aop;
import org.apache.log4j.Logger;
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.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;
import javax.servlet.http.HttpServletRequest;
import java.util.Arrays;
/****************************************************************************************
 实现AOP的切面主要有以下几个要素：
 使用@Aspect注解将一个java类定义为切面类
 使用@Pointcut定义一个切入点，可以是一个规则表达式，比如下例中某个package下的所有函数，也可以是一个注解等。
 根据需要在切入点不同位置的切入内容
 使用@Before在切入点开始处切入内容
 使用@After在切入点结尾处切入内容
 使用@AfterReturning在切入点return内容之后切入内容（可以用来对处理返回值做一些加工处理）
 使用@Around在切入点前后切入内容，并自己控制何时执行切入点自身的内容
 使用@AfterThrowing用来处理当切入内容部分抛出异常之后的处理逻辑
 使用@Order(i)注解来标识切面的优先级。i的值越小，优先级越高
 ****************************************************************************************/
/****************************************************************************************
 执行日志顺序：
 2017-10-19 20:22:35.810  INFO 9014 --- [nio-8350-exec-1] WebLogHeadAspect    : (Order(1))************** (doBefore) URL : http://localhost:8350/simple/1
 2017-10-19 20:22:35.810  INFO 9014 --- [nio-8350-exec-1] WebLogHeadAspect    : (Order(1))************** (doBefore) HTTP_METHOD : GET
 2017-10-19 20:22:35.810  INFO 9014 --- [nio-8350-exec-1] WebLogHeadAspect    : (Order(1))************** (doBefore) IP : 127.0.0.1
 2017-10-19 20:22:35.811  INFO 9014 --- [nio-8350-exec-1] WebLogHeadAspect    : (Order(1))************** (doBefore) CLASS_METHOD : com.springms.cloud.controller.SimpleProviderUserAopWebLogController.findById
 2017-10-19 20:22:35.811  INFO 9014 --- [nio-8350-exec-1] WebLogHeadAspect    : (Order(1))************** (doBefore) ARGS : [1]
 2017-10-19 20:22:35.811  INFO 9014 --- [nio-8350-exec-1] com.springms.cloud.aop.WebLogFiveAspect        : (Order(5))============== (doBefore) URL : http://localhost:8350/simple/1
 2017-10-19 20:22:35.811  INFO 9014 --- [nio-8350-exec-1] com.springms.cloud.aop.WebLogFiveAspect        : (Order(5))============== (doBefore) HTTP_METHOD : GET
 2017-10-19 20:22:35.811  INFO 9014 --- [nio-8350-exec-1] com.springms.cloud.aop.WebLogFiveAspect        : (Order(5))============== (doBefore) IP : 127.0.0.1
 2017-10-19 20:22:35.811  INFO 9014 --- [nio-8350-exec-1] com.springms.cloud.aop.WebLogFiveAspect        : (Order(5))============== (doBefore) CLASS_METHOD : com.springms.cloud.controller.SimpleProviderUserAopWebLogController.findById
 2017-10-19 20:22:35.811  INFO 9014 --- [nio-8350-exec-1] com.springms.cloud.aop.WebLogFiveAspect        : (Order(5))============== (doBefore) ARGS : [1]
 Hibernate: select user0_.id as id1_0_0_, user0_.age as age2_0_0_, user0_.balance as balance3_0_0_, user0_.name as name4_0_0_, user0_.username as username5_0_0_ from user user0_ where user0_.id=?
 2017-10-19 20:22:35.853  INFO 9014 --- [nio-8350-exec-1] com.springms.cloud.aop.WebLogFiveAspect        : (Order(5))============== (doAfterReturning) RESPONSE : User@1249202
 2017-10-19 20:22:35.853  INFO 9014 --- [nio-8350-exec-1] com.springms.cloud.aop.WebLogFiveAspect        : (Order(5))============== (doAfterReturning) SPEND TIME : 42
 2017-10-19 20:22:35.853  INFO 9014 --- [nio-8350-exec-1] WebLogHeadAspect    : (Order(1))************** (doAfterReturning) RESPONSE : User@1249202
 2017-10-19 20:22:35.853  INFO 9014 --- [nio-8350-exec-1] WebLogHeadAspect    : (Order(1))************** (doAfterReturning) SPEND TIME : 43
 总结：doBefore 方法先从优先级到低优先级依次执行完，然后 doAfterReturning 方法从低优先级到高优先级依次执行完；也就是进入从高到低，出来从低到高；
 ****************************************************************************************/
/**
 * Web层日志切面。
 *
 * @author hmilyylimh
 *
 * @version 0.0.1
 *
 * @date 2017/10/19
 *
 */
@Aspect
@Order(5)
@Component
public class WebLogFiveAspect {
    // private static final org.slf4j.Logger logger = LoggerFactory.getLogger(PreZuulFilter.class);
    private Logger logger = Logger.getLogger(getClass());
    ThreadLocal<Long> startTime = new ThreadLocal<>();
    private static final String PRE_TAG = "(Order(5))============== ";
    @Pointcut("execution(public * com.springms.cloud.controller..*.*(..))")
    public void webLog(){}
    @Before("webLog()")
    public void doBefore(JoinPoint joinPoint) throws Throwable {
        startTime.set(System.currentTimeMillis());
        // 接收到请求，记录请求内容
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
        // 记录下请求内容
        logger.info(PRE_TAG + "(doBefore) URL : " + request.getRequestURL().toString());
        logger.info(PRE_TAG + "(doBefore) HTTP_METHOD : " + request.getMethod());
        logger.info(PRE_TAG + "(doBefore) IP : " + request.getRemoteAddr());
        logger.info(PRE_TAG + "(doBefore) CLASS_METHOD : " + joinPoint.getSignature().getDeclaringTypeName() + "." + joinPoint.getSignature().getName());
        logger.info(PRE_TAG + "(doBefore) ARGS : " + Arrays.toString(joinPoint.getArgs()));
    }
    @AfterReturning(returning = "ret", pointcut = "webLog()")
    public void doAfterReturning(Object ret) throws Throwable {
        // 处理完请求，返回内容
        logger.info(PRE_TAG + "(doAfterReturning) RESPONSE : " + ret);
        logger.info(PRE_TAG + "(doAfterReturning) SPEND TIME : " + (System.currentTimeMillis() - startTime.get()));
    }
}

package com.springms.cloud.controller;
import com.springms.cloud.entity.User;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.PathVariable;
import org.springframework.web.bind.annotation.RestController;
import com.springms.cloud.repository.UserRepository;
/**
 * 用户微服务Controller。
 *
 * @author hmilyylimh
 *
 * @version 0.0.1
 *
 * @date 2017/10/19
 *
 */
@RestController
public class AopWebLogController {
    @Autowired
    private UserRepository userRepository;
    @GetMapping("/simple/{id}")
    public User findById(@PathVariable Long id) {
        return this.userRepository.findOne(id);
    }
}

package com.springms.cloud;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
/**
 * 使用AOP统一处理Web请求日志。
 *
 * @author hmilyylimh
 *
 * @version 0.0.1
 *
 * @date 2017/10/19
 *
 */
@SpringBootApplication
public class MsAopWebLogApplication {
    public static void main(String[] args) {
        SpringApplication.run(MsAopWebLogApplication.class, args);
        System.out.println("【【【【【【 AopWebLog微服务 】】】】】】已启动.");
    }
}