SpringBoot | 第二十四章：日志管理之AOP统一日志

第二十四章：日志管理之AOP统一日志

前言

上一章节，介绍了目前开发中常见的log4j2及logback日志框架的整合知识。在很多时候，我们在开发一个系统时，不管出于何种考虑，比如是审计要求，或者防抵赖，还是保留操作痕迹的角度，一般都会有个全局记录日志的模块功能。此模块一般上会记录每个对数据有进行变更的操作记录，若是在web应用上，还会记录请求的url,请求的IP,及当前的操作人，操作的方法说明等等。在很多时候，我们需要记录请求的参数信息时，通常是利用拦截器、过滤器或者AOP等来进行统一拦截。本章节，就主要来说一说如何利用AOP实现统一的web日志记录。

一点知识

何为AOP

AOP全称：Aspect Oriented Programming。是一种面向切面编程的，利用预编译方式和运行期动态代理实现程序功能统一的一种技术。它也是Spring很重要的一部分，和IOC一样重要。利用AOP可以很好的对业务逻辑的各个部分进行隔离，从而使得业务逻辑各部分之间的耦合度降低，提高程序的可重用性，同时提高了开发的效率。

简单来说，就是AOP可以在既有的程序基础上，在无代码嵌入前提下完成对相关业务的处理，业务方可以只关注自身业务的逻辑，而无需关系一些和业务无关的事项，比如最常见的日志、事务、权限检验、性能统计、统一异常处理等等。

spring官网给出的AOP介绍如下：

AOP介绍

AOP基本概念

关于AOP的相关介绍可点击官网链接查看：aop-introduction

AOP concepts

以下简单的说明下：

切面（Aspect）：切面是一个关注点的模块化，这个关注点可能是横切多个对象；
连接点（Join Point）：连接点是指在程序执行过程中某个特定的点，比如某方法调用的时候或者处理异常的时候；
通知（Advice）：指在切面的某个特定的连接点上执行的动作。Spring切面可以应用5中通知：
- 前置通知（Before）:在目标方法或者说连接点被调用前执行的通知；
- 后置通知（After）：指在某个连接点完成后执行的通知；
- 返回通知（After-returning）：指在某个连接点成功执行之后执行的通知；
- 异常通知（After-throwing）：指在方法抛出异常后执行的通知；
- 环绕通知（Around）：指包围一个连接点通知，在被通知的方法调用之前和之后执行自定义的方法。
切点（Pointcut）：指匹配连接点的断言。通知与一个切入点表达式关联，并在满足这个切入的连接点上运行，例如：当执行某个特定的名称的方法。
引入（Introduction）：引入也被称为内部类型声明，声明额外的方法或者某个类型的字段。
目标对象（Target Object）：目标对象是被一个或者多个切面所通知的对象。
AOP代理（AOP Proxy）：AOP代理是指AOP框架创建的对对象，用来实现切面契约（包括通知方法等功能）
织入（Wearving）：指把切面连接到其他应用出程序类型或者对象上，并创建一个被通知的对象。或者说形成代理对象的方法的过程。

以下这张图，对以上部分概念进行简单介绍：

image

代理机制

Spirng的AOP的动态代理实现机制有两种，分别是：JDK动态代理和CGLib动态代理。简单介绍下两种代理机制。

JDK动态代理

JDK动态代理是面向接口的代理模式，如果被代理目标没有接口那么Spring也无能为力，Spring通过java的反射机制生产被代理接口的新的匿名实现类，重写了其中AOP的增强方法。

CGLib动态代理

CGLib是一个强大、高性能的Code生产类库，可以实现运行期动态扩展java类，Spring在运行期间通过 CGlib继承要被动态代理的类，重写父类的方法，实现AOP面向切面编程。

两者对比：

JDK动态代理是面向接口，在创建代理实现类时比CGLib要快，创建代理速度快。而且JDK动态代理只能对实现了接口的类生成代理，而不能针对类。
CGLib动态代理是通过字节码底层继承要代理类来实现（如果被代理类被final关键字所修饰，那么抱歉会失败），在创建代理这一块没有JDK动态代理快，但是运行速度比JDK动态代理要快。

至于相关原理，大家自行搜索下吧，⊙﹏⊙‖∣

切入点指示符简单介绍

为了能够灵活定义切入点位置，Spring AOP提供了多种切入点指示符。以下简单的介绍下。

execution：匹配执行方法的连接点

execution切入点指示符

可以从上图中，看见切入点指示符execution的语法结构为：execution（modifiers-pattern? ret-type-pattern declaring-type-pattern? name-pattern（param-pattern） throws-pattern?）。这也是最常使用的一个指示符了。

within：用于匹配指定类型内的方法执行；
this：用于匹配当前AOP代理对象类型的执行方法；注意是AOP代理对象的类型匹配，这样就可能包括引入接口也类型匹配；
target：用于匹配当前目标对象类型的执行方法；注意是目标对象的类型匹配，这样就不包括引入接口也类型匹配；
args：用于匹配当前执行的方法传入的参数为指定类型的执行方法；
@within：用于匹配所以持有指定注解类型内的方法；
@target：用于匹配当前目标对象类型的执行方法，其中目标对象持有指定的注解；
@args：用于匹配当前执行的方法传入的参数持有指定注解的执行；
@annotation：用于匹配当前执行方法持有指定注解的方法；
bean：Spring AOP扩展的，AspectJ没有对于指示符，用于匹配特定名称的Bean对象的执行方法；
reference pointcut：表示引用其他命名切入点，只有@ApectJ风格支持，Schema风格不支持。

对于相关的语法和使用，大家可查看：https://blog.csdn.net/zhengchao1991/article/details/53391244。里面有较为详细的介绍。这里就不多加阐述了。

统一日志记录

介绍完相关知识后，我们开始来使用AOP实现统一的日志记录功能。本文直接利用@Around环绕模式来实现，同时自定义一个日志注解类，来个性化记录日志信息。

0.加入Aop依赖。

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

1.编写自定义日志注解类Log。

/**
 * 日志注解类
 * @author oKong
 *
 */
@Documented
@Retention(RetentionPolicy.RUNTIME)
@Target({ElementType.METHOD})//只能在方法上使用此注解
public @interface Log {
    /**
     * 日志描述，这里使用了@AliasFor 别名。spring提供的
     * @return
     */
    @AliasFor("desc")
    String value() default "";
    
    /**
     * 日志描述
     * @return
     */
    @AliasFor("value")
    String desc() default "";
    
    /**
     * 是否不记录日志
     * @return
     */
    boolean ignore() default false;
}

友情提示：熟悉Spring常用注解类的朋友，对@AliasFor应该不陌生。它是Spring提供的一个注解，主要是给注解的属性起名别的。让使用注解时，更加的容易理解（比如给value属性起别名）。一般上是配对别名。由于是Spring框架提供的，所以要使其生效，可以使用AnnotationUtils.synthesizeAnnotation或者AnnotationUtils.getAnnotation方法调用获取注解，以下代码中会有个简单示例。

2.编写切面类。

/**
 * 日志切面类
 * @author xiedeshou
 *
 */
//加入@Aspect 申明一个切面
@Aspect
@Component
@Slf4j
public class LogAspect {
    
    //设置切入点：这里直接拦截被@RestController注解的类
    @Pointcut("within(@org.springframework.web.bind.annotation.RestController *)")
    public void pointcut() {
        
    }
    
    /**
     * 切面方法,记录日志
     * @return
     * @throws Throwable 
     */
    @Around("pointcut()")
    public Object doAround(ProceedingJoinPoint joinPoint) throws Throwable {
        long beginTime = System.currentTimeMillis();//1、开始时间 
        //利用RequestContextHolder获取requst对象
        ServletRequestAttributes requestAttr = (ServletRequestAttributes)RequestContextHolder.currentRequestAttributes();
        String uri = requestAttr.getRequest().getRequestURI();
        log.info("开始计时: {}  URI: {}", new Date(),uri);
        //访问目标方法的参数 可动态改变参数值
        Object[] args = joinPoint.getArgs();
        //方法名获取
        String methodName = joinPoint.getSignature().getName();
        log.info("请求方法：{}, 请求参数: {}", methodName, Arrays.toString(args));
        //可能在反向代理请求进来时，获取的IP存在不正确行 这里直接摘抄一段来自网上获取ip的代码
        log.info("请求ip：{}", getIpAddr(requestAttr.getRequest()));
                
        Signature signature = joinPoint.getSignature();
        if(!(signature instanceof MethodSignature)) {
            throw new IllegalArgumentException("暂不支持非方法注解");
        }
        //调用实际方法
        Object object = joinPoint.proceed();
        //获取执行的方法
        MethodSignature methodSign = (MethodSignature) signature;
        Method method = methodSign.getMethod();
        //判断是否包含了 无需记录日志的方法
        Log logAnno = AnnotationUtils.getAnnotation(method, Log.class);
        if(logAnno != null && logAnno.ignore()) {
            return object;
        } 
        log.info("log注解描述：{}", logAnno.desc());
        long endTime = System.currentTimeMillis();
        log.info("结束计时: {},  URI: {},耗时：{}", new Date(),uri,endTime - beginTime);
        //模拟异常
        //System.out.println(1/0);
        return object;
    }
    
    /**
     * 指定拦截器规则；也可直接使用within(@org.springframework.web.bind.annotation.RestController *)
     * 这样简单点 可以通用
     * @param 异常对象
     */
    @AfterThrowing(pointcut="pointcut()",throwing="e")
    public void afterThrowable(Throwable e) {
        log.error("切面发生了异常：", e);
        //这里可以做个统一异常处理
        //自定义一个异常 包装后排除
        //throw new AopException("xxx);
    }

    /**
     * 转至：https://my.oschina.net/u/994081/blog/185982
     */
    public static String getIpAddr(HttpServletRequest request) {
        String ipAddress = null;
        try {
            ipAddress = request.getHeader("x-forwarded-for");
            if (ipAddress == null || ipAddress.length() == 0 || "unknown".equalsIgnoreCase(ipAddress)) {
                ipAddress = request.getHeader("Proxy-Client-IP");
            }
            if (ipAddress == null || ipAddress.length() == 0 || "unknown".equalsIgnoreCase(ipAddress)) {
                ipAddress = request.getHeader("WL-Proxy-Client-IP");
            }
            if (ipAddress == null || ipAddress.length() == 0 || "unknown".equalsIgnoreCase(ipAddress)) {
                ipAddress = request.getRemoteAddr();
                if (ipAddress.equals("127.0.0.1")) {
                    // 根据网卡取本机配置的IP
                    InetAddress inet = null;
                    try {
                        inet = InetAddress.getLocalHost();
                    } catch (UnknownHostException e) {
                        log.error("获取ip异常：{}" ,e.getMessage());
                        e.printStackTrace();
                    }
                    ipAddress = inet.getHostAddress();
                }
            }
            // 对于通过多个代理的情况，第一个IP为客户端真实IP,多个IP按照','分割
            if (ipAddress != null && ipAddress.length() > 15) { // "***.***.***.***".length()
                                                                // = 15
                if (ipAddress.indexOf(",") > 0) {
                    ipAddress = ipAddress.substring(0, ipAddress.indexOf(","));
                }
            }
        } catch (Exception e) {
            ipAddress = "";
        }
        // ipAddress = this.getRequest().getRemoteAddr();

        return ipAddress;
    }    
}

3.启动类加入注解@EnableAspectJAutoProxy，生效注解。另一说法，默认引入pom依赖就是默认开启的。无所谓，加了就是了，加上总之是个好习惯，因为不知道后续版本是否会修改默认值呢~

@SpringBootApplication
@EnableAspectJAutoProxy
@Slf4j
public class Chapter24Application {

    public static void main(String[] args) {
        SpringApplication.run(Chapter24Application.class, args);
        log.info("Chapter24启动!");
    }
}

4.编写控制层。

/**
 * aop统一异常示例
 * @author xiedeshou
 *
 */
@RestController
public class DemoController {
    /**
     * 简单方法示例
     * @param hello
     * @return
     */
    @RequestMapping("/aop")
    @Log(value="请求了aopDemo方法")
    public String aopDemo(String hello) {
        return "请求参数为：" + hello;
    }

    /**
     * 不拦截日志示例
     * @param hello
     * @return
     */
    @RequestMapping("/notaop")
    @Log(ignore=true)
    public String notAopDemo(String hello) {
        return "此方法不记录日志，请求参数为：" + hello;
    }
}

友情提示：在编写了切面类后，若符合切面拦截条件的方法，IDE会进行标识的。

切面提示

5.启动应用，访问api,即可看见控制台输出了对应信息了。

访问了：/aop，输出

2018-08-23 22:54:59.003  INFO 12928 --- [nio-8080-exec-3] c.l.l.s.chapter24.config.LogAspect       : 开始计时: Fri Aug 23 22:54:59 CST 2018  URI: /aop
2018-08-23 22:54:59.004  INFO 12928 --- [nio-8080-exec-3] c.l.l.s.chapter24.config.LogAspect       : 请求方法：aopDemo, 请求参数: [oKong]
2018-08-23 22:54:59.005  INFO 12928 --- [nio-8080-exec-3] c.l.l.s.chapter24.config.LogAspect       : 请求ip：192.168.2.107
2018-08-23 22:54:59.005  INFO 12928 --- [nio-8080-exec-3] c.l.l.s.chapter24.config.LogAspect       : log注解描述：请求了aopDemo方法
2018-08-23 22:54:59.005  INFO 12928 --- [nio-8080-exec-3] c.l.l.s.chapter24.config.LogAspect       : 结束计时: Fri Aug 23 22:54:59 CST 2018,  URI: /aop,耗时：2

参考资料

总结

本文主要是简单介绍了利用AOP实现统一的web日志记录功能。本示例未演示日志入库功能，大家可自行实现。在实际开发过程中，一般上都是将日志保存进行异步化后进行入库处理的，这点需要注意，日志记录不能影响正常的方法请求，若是同步的，会本末倒置的。本文只是简单的使用环绕机制进行讲解，大家还可以试试其他的注解进行相应实践下，大都大同小异，只是要注意下各注解的触发时机。