Spring aop+自定义注解统一记录用户行为日志

写在前面

本文不涉及过多的Spring aop基本概念以及基本用法介绍，以实际场景使用为主。

场景

我们通常有这样一个需求：打印后台接口请求的具体参数，打印接口请求的最终响应结果，以及记录哪个用户在什么时间点，访问了哪些接口，接口响应耗时多长时间等等。这样做的目的是为了记录用户的访问行为，同时便于跟踪接口调用情况，以便于出现问题时能够快速定位问题所在。

最简单的做法是这样的：

@GetMapping(value = "/info")
    public BaseResult userInfo() {
        //1.打印接口入参日志信息,标记接口访问时间戳
        BaseResult result = mUserService.userInfo();
        //2.打印/入库 接口响应信息，响应时间等
        return result;
    }

这种做法没毛病，但是稍微比较敏感的同学就会发觉有以下缺点：

• 每个接口都充斥着重复的代码，有没有办法提取这部分代码，做到统一管理呢？答案是使用 Spring aop 面向切面执行这段公共代码。
• 充斥着 硬编码 的味道，有些场景会要求在接口响应结束后，打印日志信息，保存到数据库，甚至要把日志记录到elk日志系统等待，同时这些操作要做到可控，有没有什么操作可以直接声明即可？答案是使用自定义注解，声明式的处理访问日志。

自定义注解

新增日志注解类，注解作用于方法级别，运行时起作用。

@Target({ElementType.METHOD}) //注解作用于方法级别
@Retention(RetentionPolicy.RUNTIME) //运行时起作用
public @interface Loggable {

    /**
     * 是否输出日志
     */
    boolean loggable() default true;

    /**
     * 日志信息描述,可以记录该方法的作用等信息。
     */
    String descp() default "";

    /**
     * 日志类型，可能存在多种接口类型都需要记录日志，比如dubbo接口，web接口
     */
    LogTypeEnum type() default LogTypeEnum.WEB;

    /**
     * 日志等级
     */
    String level() default "INFO";

    /**
     * 日志输出范围,用于标记需要记录的日志信息范围，包含入参、返回值等。
     * ALL-入参和出参, BEFORE-入参, AFTER-出参
     */
    LogScopeEnum scope() default LogScopeEnum.ALL;

    /**
     * 入参输出范围，值为入参变量名，多个则逗号分割。不为空时，入参日志仅打印include中的变量
     */
    String include() default "";

    /**
     * 是否存入数据库
     */
    boolean db() default true;

    /**
     * 是否输出到控制台
     *
     * @return
     */
    boolean console() default true;
}

日志类型枚举类:

public enum LogTypeEnum {

    WEB("-1"), DUBBO("1"), MQ("2");

    private final String value;

    LogTypeEnum(String value) {
        this.value = value;
    }

    public String value() {
        return this.value;
    }
}

日志作用范围枚举类：

public enum LogScopeEnum {

    ALL, BEFORE, AFTER;

    public boolean contains(LogScopeEnum scope) {
        if (this == ALL) {
            return true;
        } else {
            return this == scope;
        }
    }

    @Override
    public String toString() {
        String str = "";
        switch (this) {
            case ALL:
                break;
            case BEFORE:
                str = "REQUEST";
                break;
            case AFTER:
                str = "RESPONSE";
                break;
            default:
                break;
        }
        return str;
    }
}

相关说明已在代码中注释，这里不再说明。

使用 Spring aop 重构

引入依赖：

<dependency>
            <groupId>org.aspectj</groupId>
            <artifactId>aspectjweaver</artifactId>
            <version>1.8.8</version>
        </dependency>
        <dependency>
            <groupId>org.aspectj</groupId>
            <artifactId>aspectjrt</artifactId>
            <version>1.8.13</version>
        </dependency>
        <dependency>
            <groupId>org.javassist</groupId>
            <artifactId>javassist</artifactId>
            <version>3.22.0-GA</version>
    </dependency>

配置文件启动aop注解，基于类的代理，并且在 spring 中注入 aop 实现类。

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
    .....省略部分代码">

    <!-- 扫描controller -->
    <context:component-scan base-package="**.*controller"/>
    <context:annotation-config/>

    <!-- 启动aop注解基于类的代理（这时需要cglib库），如果proxy-target-class属值被设置为false或者这个属性被省略，那么标准的JDK 基于接口的代理将起作用 -->
    <aop:config proxy-target-class="true"/>
    
     <!-- web层日志记录AOP实现 -->
    <bean class="com.easywits.common.aspect.WebLogAspect"/>
</beans>

新增 WebLogAspect 类实现

/**
 * 日志记录AOP实现
 * create by zhangshaolin on 2018/5/1
 */
@Aspect
@Component
public class WebLogAspect {

    private static final Logger LOGGER = LoggerFactory.getLogger(WebLogAspect.class);

    // 开始时间
    private long startTime = 0L;

    // 结束时间
    private long endTime = 0L;

    /**
     * Controller层切点
     */
    @Pointcut("execution(* *..controller..*.*(..))")
    public void controllerAspect() {
    }

    /**
     * 前置通知 用于拦截Controller层记录用户的操作
     *
     * @param joinPoint 切点
     */
    @Before("controllerAspect()")
    public void doBeforeInServiceLayer(JoinPoint joinPoint) {
    }

    /**
     * 配置controller环绕通知,使用在方法aspect()上注册的切入点
     *
     * @param point 切点
     * @return
     * @throws Throwable
     */
    @Around("controllerAspect()")
    public Object doAround(ProceedingJoinPoint point) throws Throwable {
        // 获取request
        RequestAttributes requestAttributes = RequestContextHolder.getRequestAttributes();
        ServletRequestAttributes servletRequestAttributes = (ServletRequestAttributes) requestAttributes;
        HttpServletRequest request = servletRequestAttributes.getRequest();

        //目标方法实体
        Method method = ((MethodSignature) point.getSignature()).getMethod();
        boolean hasMethodLogAnno = method
                .isAnnotationPresent(Loggable.class);
        //没加注解 直接执行返回结果
        if (!hasMethodLogAnno) {
            return point.proceed();
        }

        //日志打印外部开关默认关闭
        String logSwitch = StringUtils.equals(RedisUtil.get(BaseConstants.CACHE_WEB_LOG_SWITCH), BaseConstants.YES) ? BaseConstants.YES : BaseConstants.NO;

        //记录日志信息
        LogMessage logMessage = new LogMessage();

        //方法注解实体
        Loggable methodLogAnnon = method.getAnnotation(Loggable.class);
        
        //处理入参日志
        handleRequstLog(point, methodLogAnnon, request, logMessage, logSwitch);
        
        //执行目标方法内容，获取执行结果
        Object result = point.proceed();
        
        //处理接口响应日志
        handleResponseLog(logSwitch, logMessage, methodLogAnnon, result);
        return result;
    }
    
    /**
     * 处理入参日志
     *
     * @param point          　切点
     * @param methodLogAnnon 　日志注解
     * @param logMessage     　日志信息记录实体
     */
    private void handleRequstLog(ProceedingJoinPoint point, Loggable methodLogAnnon, HttpServletRequest request,
                                 LogMessage logMessage, String logSwitch) throws Exception {

        String paramsText = "";
        //参数列表
        String includeParam = methodLogAnnon.include();
        Map<String, Object> methodParamNames = getMethodParamNames(
                point.getTarget().getClass(), point.getSignature().getName(), includeParam);
        Map<String, Object> params = getArgsMap(
                point, methodParamNames);
        if (params != null) {
            //序列化参数列表
            paramsText = JSON.toJSONString(params);
        }
        logMessage.setParameter(paramsText);
        //判断是否输出日志
        if (methodLogAnnon.loggable()
                && methodLogAnnon.scope().contains(LogScopeEnum.BEFORE)
                && methodLogAnnon.console()
                && StringUtils.equals(logSwitch, BaseConstants.YES)) {
            //打印入参日志
            LOGGER.info("【{}】 接口入参成功!, 方法名称:【{}】, 请求参数:【{}】", methodLogAnnon.descp().toString(), point.getSignature().getName(), paramsText);
        }
        startTime = System.currentTimeMillis();
        //接口描述
        logMessage.setDescription(methodLogAnnon.descp().toString());
        
        //...省略部分构造logMessage信息代码
    }

    /**
     * 处理响应日志
     *
     * @param logSwitch         外部日志开关，用于外部动态开启日志打印
     * @param logMessage        日志记录信息实体
     * @param methodLogAnnon    日志注解实体
     * @param result         　 接口执行结果
     */
    private void handleResponseLog(String logSwitch, LogMessage logMessage, Loggable methodLogAnnon, Object result) {
        endTime = System.currentTimeMillis();
        //结束时间
        logMessage.setEndTime(DateUtils.getNowDate());
        //消耗时间
        logMessage.setSpendTime(endTime - startTime);
        //是否输出日志
        if (methodLogAnnon.loggable()
                && methodLogAnnon.scope().contains(LogScopeEnum.AFTER)) {
            //判断是否入库
            if (methodLogAnnon.db()) {
                //...省略入库代码
            }
            //判断是否输出到控制台
            if (methodLogAnnon.console() 
                    && StringUtils.equals(logSwitch, BaseConstants.YES)) {
                //...省略打印日志代码
            }
        }
    }
    /**
     * 获取方法入参变量名
     *
     * @param cls        触发的类
     * @param methodName 触发的方法名
     * @param include    需要打印的变量名
     * @return
     * @throws Exception
     */
    private Map<String, Object> getMethodParamNames(Class cls,
                                                    String methodName, String include) throws Exception {
        ClassPool pool = ClassPool.getDefault();
        pool.insertClassPath(new ClassClassPath(cls));
        CtMethod cm = pool.get(cls.getName()).getDeclaredMethod(methodName);
        LocalVariableAttribute attr = (LocalVariableAttribute) cm
                .getMethodInfo().getCodeAttribute()
                .getAttribute(LocalVariableAttribute.tag);

        if (attr == null) {
            throw new Exception("attr is null");
        } else {
            Map<String, Object> paramNames = new HashMap<>();
            int paramNamesLen = cm.getParameterTypes().length;
            int pos = Modifier.isStatic(cm.getModifiers()) ? 0 : 1;
            if (StringUtils.isEmpty(include)) {
                for (int i = 0; i < paramNamesLen; i++) {
                    paramNames.put(attr.variableName(i + pos), i);
                }
            } else { // 若include不为空
                for (int i = 0; i < paramNamesLen; i++) {
                    String paramName = attr.variableName(i + pos);
                    if (include.indexOf(paramName) > -1) {
                        paramNames.put(paramName, i);
                    }
                }
            }
            return paramNames;
        }
    }

    /**
     * 组装入参Map
     *
     * @param point　　　　　　　切点
     * @param methodParamNames　参数名称集合
     * @return
     */
    private Map getArgsMap(ProceedingJoinPoint point,
                           Map<String, Object> methodParamNames) {
        Object[] args = point.getArgs();
        if (null == methodParamNames) {
            return Collections.EMPTY_MAP;
        }
        for (Map.Entry<String, Object> entry : methodParamNames.entrySet()) {
            int index = Integer.valueOf(String.valueOf(entry.getValue()));
            if (args != null && args.length > 0) {
                Object arg = (null == args[index] ? "" : args[index]);
                methodParamNames.put(entry.getKey(), arg);
            }
        }
        return methodParamNames;
    }
}

使用注解的方式处理接口日志

接口改造如下：

@Loggable(descp = "用户个人资料", include = "")
    @GetMapping(value = "/info")
    public BaseResult userInfo() {
        return mUserService.userInfo();
    }

可以看到，只添加了注解@Loggable，所有的web层接口只需要添加@Loggable注解就能实现日志处理了，方便简洁！最终效果如下：

访问入参，响应日志信息：

用户行为日志入库部分信息：

简单总结

• 编写代码时，看到重复性代码应当立即重构，杜绝重复代码。
• Spring aop　可以在方法执行前，执行时，执行后切入执行一段公共代码，非常适合用于公共逻辑处理。
• 自定义注解，声明一种行为，使配置简化，代码层面更加简洁。

最后

更多原创文章会第一时间推送公众号【张少林同学】，欢迎关注！