利用AOP进行日志统计

日志级别

TRACE, DEBUG, INFO, WARN, ERROR, FATAL, OFF

AOP+注解

下面给出一个简单的日志示例

AOP面向切面编程包含三步

定义切面

切面逻辑

织入 (spring帮助我们完成)

首先定义SysLog注解如下

@Target({ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
@Documented
public @interface SysLog {
    String value() default "";
}

接着我们定义AOP类

@Aspect
@Component
@Slf4j
public class SysLogAOP {

    // 定义切面
    @Pointcut("@annotation(com.danxiaocampus.api.common.annotation.SysLog)")
    public void logPointcut(){
    }

    @Around(value= "logPointcut()")
    public Object run(ProceedingJoinPoint joinPoint) throws Throwable {
        Object[] args = joinPoint.getArgs();
        Signature signature =  joinPoint.getSignature();//方法签名
        Method method = ( (MethodSignature)signature ).getMethod();
        //这个方法才是目标对象上有注解的方法
        Method realMethod = joinPoint.getTarget().getClass().getDeclaredMethod(signature.getName(), method.getParameterTypes());
        Annotation[] annotations = realMethod.getAnnotations();
        //获取注解
        SysLog sysLog = realMethod.getAnnotation(SysLog.class);
        if(sysLog != null){
            String now = new SimpleDateFormat("yy-MM-dd HH:mm:ss").format(new Date());
            log.info(now+" 执行内容: {}",sysLog.value());
            return joinPoint.proceed(args);
        } else {
            //没有这个注解的不验证登录，继续处理业务
            return joinPoint.proceed(args);
        }
    }
}

接着我们在一个登录方法上面加上注解

启动项目, 访问接口 , 查看控制台

这里只是简单的实现AOP的代码逻辑 , 后面再详细的添加日志的各项参数

根据日志级别分文件存放并打包

首先更改项目配置文件 , 设置配置文件为我们下面需要进行的配置文件

1 2	logging: config: classpath:logback-spring.xml

接着在resources目录中创建logback-spring.xml 文件, 然后复制下面的内容

这里文件名随便起名, 不过需要跟配置文件中的文件名对应 , 文件名需要浅显易懂

默认设置控制台输出的日志级别为info

logs这里使用的为相对路径 , 目录默认与项目目录同级别

<configuration debug="false" scan="true" scanPeriod="10 seconds">
    <contextName>logback</contextName>

    <!--  自定义变量  -->
    <property name="path" value="../logs"/>
    <property name="maxFileSize" value="800MB"/>
    <property name="maxHistory" value="30"/>

    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>info</level>
        </filter>
        <encoder>
            <pattern>%date [%level] [%thread] %logger{36} [%file : %line] %msg%n
            </pattern>
        </encoder>
    </appender>

    <appender name="debug_file" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${path}/logback_debug.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 每天一归档 -->
            <fileNamePattern>${path}/logback_debug.log.%d{yyyy-MM-dd}-%i.zip</fileNamePattern>
            <maxHistory>${maxHistory}</maxHistory>
            <timeBasedFileNamingAndTriggeringPolicy
                    class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>${maxFileSize}</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>
        <encoder>
            <pattern>%date [%level] [%thread] %logger{36} [%file : %line] %msg%n
            </pattern>
        </encoder>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>DEBUG</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>

    <appender name="info_file" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${path}/logback_info.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 每天一归档 -->
            <fileNamePattern>${path}/logback_info.log.%d{yyyy-MM-dd}-%i.zip</fileNamePattern>
            <maxHistory>${maxHistory}</maxHistory>
            <timeBasedFileNamingAndTriggeringPolicy
                    class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>${maxFileSize}</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>
        <encoder>
            <pattern>%date [%level] [%thread] %logger{36} [%file : %line] %msg%n
            </pattern>
        </encoder>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>INFO</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>

    <appender name="warn_file" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${path}/logback_warn.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 每天一归档 -->
            <fileNamePattern>${path}/logback_warn.log.%d{yyyy-MM-dd}-%i.zip</fileNamePattern>
            <maxHistory>${maxHistory}</maxHistory>
            <timeBasedFileNamingAndTriggeringPolicy
                    class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>${maxFileSize}</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>
        <encoder>
            <pattern>%date [%level] [%thread] %logger{36} [%file : %line] %msg%n
            </pattern>
        </encoder>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>WARN</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>


    <appender name="error_file" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${path}/logback_error.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 每天一归档 -->
            <fileNamePattern>${path}/logback_error.log.%d{yyyy-MM-dd}-%i.zip</fileNamePattern>
            <maxHistory>${maxHistory}</maxHistory>
            <timeBasedFileNamingAndTriggeringPolicy
                    class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>${maxFileSize}</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>
        <encoder>
            <pattern>%date [%level] [%thread] %logger{36} [%file : %line] %msg%n
            </pattern>
        </encoder>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>

    <!-- 控制台输出日志级别 -->
    <root level="info">
        <appender-ref ref="console"/>
    </root>

    <!-- 指定项目中某个包，当有日志操作行为时的日志记录级别 -->
    <logger name="com.danxiaocampus.api" level="DEBUG">
        <appender-ref ref="debug_file"/>
        <appender-ref ref="info_file"/>
        <appender-ref ref="warn_file"/>
        <appender-ref ref="error_file"/>
    </logger>
</configuration>

日志各项数据

LogParam

@Data
static class LogParam {
    /**
         * 访问用户
         */
    private Long userId;
    /**
         * 用户传入的参数
         */
    private Map<String,Object> methodParams;

    /**
         *  用户访问的接口url
         */
    private String url;

    /**
         *  请求方式
         */
    private String httpMethod;

    LogParam(int capacity){
        methodParams =new HashMap<>(capacity);
    }

}

统计接口信息

记录接口信息的时候遇到了一个问题 , 就是一般我们定义接口都会使用多个注解 @XXXMapping() , 这里的处理思路是通过反射去获取被@SysLog注解修饰的方法 ,

然后通过反射去获取方法上面的注解, 然后获取注解的类型 , 进行遍历

这里切忌直接使用target对象的getClass() 方法, 虽然我这里通过自己封装的AopUtile的工具类进行操作 , 返回真实的对象 , 但是在debug的过程中发现并非如此 ,

1 2	Annotation target = (Annotation)AopUtil.getTarget(annotation); // 获取真实注解对象 Class<? extends Annotation> aClass = target.annotationType(); // 注解的类

这里AopUtil判断的方式是通过spring提供的AopUtils工具类的isAopProxy(Object obj)方法 , 但是在实际过程中发现此方法并不能如愿,

因此不能直接使用getClass()方法

如果getTarget()并没有返回真实的对象, 仍然是代理对象, 那么我们调用getClass()方法得到的结果就是代理对象的类 , 这里为com.sun.Proxy ,

正确的做法是使用annotationType()方法来获取注解的类型。

完整的getTarget()方法

public static Object getTarget(Object proxy) throws Exception {
    if (!AopUtils.isAopProxy(proxy)) {
        return proxy;
    }
    if (AopUtils.isJdkDynamicProxy(proxy)) {
        /**JDK动态代理*/
        return getJdkDynamicProxyTargetObject(proxy);
    } else if(AopUtils.isCglibProxy(proxy)){
        /**cglib动态代理*/
        return getCglibProxyTargetObject(proxy);
    }
    return proxy;
}

那么接着来分析 @XXXMapping

对于一般的@RequestMapping , 修饰该注解的注解为@Mapping

@Target({ElementType.TYPE, ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
@Documented
@Mapping
public @interface RequestMapping {

	String name() default "";

	@AliasFor("path")
	String[] value() default {};

	@AliasFor("value")
	String[] path() default {};

	RequestMethod[] method() default {};

	String[] params() default {};

	String[] headers() default {};

	String[] consumes() default {};

	String[] produces() default {};
}

但是对于@GetMapping这种 , 他这里套了一个@AliasFor

@AliasFor

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
@Documented
@RequestMapping(method = RequestMethod.GET)
public @interface GetMapping {

	/**
	 * Alias for {@link RequestMapping#name}.
	 */
	@AliasFor(annotation = RequestMapping.class)
	String name() default "";

	/**
	 * Alias for {@link RequestMapping#value}.
	 */
	@AliasFor(annotation = RequestMapping.class)
	String[] value() default {};

	/**
	 * Alias for {@link RequestMapping#path}.
	 */
	@AliasFor(annotation = RequestMapping.class)
	String[] path() default {};

	/**
	 * Alias for {@link RequestMapping#params}.
	 */
	@AliasFor(annotation = RequestMapping.class)
	String[] params() default {};

	/**
	 * Alias for {@link RequestMapping#headers}.
	 */
	@AliasFor(annotation = RequestMapping.class)
	String[] headers() default {};

	/**
	 * Alias for {@link RequestMapping#consumes}.
	 * @since 4.3.5
	 */
	@AliasFor(annotation = RequestMapping.class)
	String[] consumes() default {};

	/**
	 * Alias for {@link RequestMapping#produces}.
	 */
	@AliasFor(annotation = RequestMapping.class)
	String[] produces() default {};

}

简单来说 , @AliasFor可以定义一个注解中的两个属性互为别名。

用到注解属性上，表示两个属性互相为别名，互相为别名的属性值必须相同，若设置成不同，则会报错
注解是可以继承的，但是注解是不能继承父注解的属性的 , 也就是说 , 我在类扫描的时候 , 拿到的注解的属性值依然是父注解的属性值 , 而不是你定义的注解的属性值 , 所以此时可以在子注解对应的属性上加上@AliasFor

那么结合上面的源码来对比 , 这里的@AliasFor(annotation = RequestMapping.class) 相当于定义了父注解为@RequestMapping

这里我们为了区分@ReqeustMapping 以及@GetMapping 直接通过反射获取对象上面的注解 , 然后进行判断即可 ,

这里我们通过注解上面的@RequestMapping 只能判断当前的注解不是@RequestMapping , 不能判断这个注解到底是@GetMaping 还是@PostMapping ,

即便我们可以通过annotationType() 方法直接注解的类型, 但是却无法在代码中进行相应类型的强制转换 , 因为你不能写出

GetMapping getMapping = (aClass)annotation; 这样的代码 , 那么目前考虑到两种办法来进行操作

通过解析注解的toString()方法的结果 , 即能获取到数据(value等) , 也能获取到注解的类型 , 缺点是操作起来比较复杂

使用if-else 挨个判断 , 这里注解不多, 只需要几个if-else即可得出我们想要的结果, 缺点是代码看起来比较冗余 , 并且不方便后续维护

或许你会感到奇怪 , 既然这里已经使用反射了, 为什么不直接通过反射来获取到对象的值呢?

我们通过aClass对象上面的注解 , 可以确定当前接口使用的注解是什么 GetMapping (不唯一) 或者是ReqeustMapping

通过aClass获取不到注解的Field

方便起见 , 这里暂时使用if-else实现代码逻辑

为了避免日志妨碍正常的业务逻辑 , 获取annotation的地方使用try-catch包裹

for (Annotation annotation : annotations) {
    Annotation target = (Annotation)AopUtil.getTarget(annotation); // 获取真实注解对象
    Class<? extends Annotation> aClass = target.annotationType(); // 注解的类
    // 注解上面的注解
    // 如果注解的头上包含有@Mapping() 或者 @RequestMapping()
    if(aClass.getAnnotation(Mapping.class)!=null){
        RequestMapping requestMapping = (RequestMapping)annotation;
        RequestMethod[] httpMethod = requestMapping.method();
        String[] value = requestMapping.value();
        this.httpMethod=httpMethod[0].toString(); // 获取不到value
        this.url=value[0];
    }else if(aClass.getAnnotation(RequestMapping.class)!=null){
        // 注解是其他的注解(GetMapping ,PostMapping等)
        try{
            if(annotation instanceof GetMapping){
                GetMapping getMapping= (GetMapping)annotation;
                String[] value = getMapping.value();
                this.httpMethod=HttpMethod.GET.toString(); // 强制转换获取不到value
                this.url=value[0];
            }else if(annotation instanceof PostMapping){
                PostMapping getMapping= (PostMapping)annotation;
                String[] value = getMapping.value();
                this.httpMethod=HttpMethod.POST.toString(); // 强制转换获取不到value
                this.url=value[0];
            }else if(annotation instanceof DeleteMapping){
                DeleteMapping getMapping= (DeleteMapping)annotation;
                String[] value = getMapping.value();
                this.httpMethod=HttpMethod.DELETE.toString(); // 强制转换获取不到value
                this.url=value[0];
            }else if(annotation instanceof PutMapping){
                PutMapping getMapping= (PutMapping)annotation;
                String[] value = getMapping.value();
                this.httpMethod=HttpMethod.PUT.toString(); // 强制转换获取不到value
                this.url=value[0];
            }
        }catch (Exception e) {
            log.error("获取接口注解失败 ,注解为 {}",aClass);
        }
    }
}

使用

这里主要统计了用户 , 请求方式 , 请求路径 , 执行内容 , 参数

对于执行失败会添加失败原因 , 通过returnResult获得
执行内容需要手动添加, 通过@SysLog(value = "**") 来添加

@Pointcut("@annotation(com.danxiaocampus.api.common.annotation.SysLog)")
public void logPointcut(){
}

@Around(value= "logPointcut()")
public Object run(ProceedingJoinPoint joinPoint) throws Throwable {
    Object[] args = joinPoint.getArgs();
    Signature signature =  joinPoint.getSignature();//方法签名
    Method method = ( (MethodSignature)signature ).getMethod();
    //这个方法才是目标对象上有注解的方法
    Method realMethod = joinPoint.getTarget().getClass().getDeclaredMethod(signature.getName(), method.getParameterTypes());
    //获取注解
    SysLog sysLog = realMethod.getAnnotation(SysLog.class);
    Object proceed = joinPoint.proceed(args);
    if(proceed instanceof ReturnResult){
        ReturnResult result = (ReturnResult) proceed;
        LogParam params = getParams(joinPoint);
        params.setAPIInfo(method); // 统计接口信息
        if(result.getStatus()==0 || result.getStatus()==200){
            // 执行成功
            log.info("[成功] 用户Id:{}, 请求方式: {} , 请求路径: {} , 执行内容: {} , 参数: {}",
                     params.getUserId(),params.getHttpMethod(),params.getUrl(),sysLog.value(),params.getMethodParams());
        }else{
            // 执行失败
            log.info("[失败] 用户Id:{}, 请求方式: {} , 请求路径: {} , 执行内容: {},失败原因:{} ,参数: {}",params.getUserId(),params.getHttpMethod(),params.getUrl(),sysLog.value(),result.getErrorMessage(),params.getMethodParams());
        }
        return result;
    }else{
        return proceed;
    }
}