Spring aop拦截springmvc的controller请求方法，添加日志和统计方法执行时间

前言

系统最近莫名挂了三次，查看log日志没找到原因，因为只有少数功能日志输出，大部分功能都没记录日志。打算通过spring aop来给springmvc的controller层的方法加日志，进入方法，方法执行完都记录日志，同时记录方法执行的耗时。日志输出级别为debug，通过log4j的分级别输出日志到不同的文件，下面记录下aop拦截的步骤。

1.applicationContext.xml中的配置

<!--开启注解-->
<context:annotation-config />

<!-- 使用annotation 自动注册bean,并保证@Required,@Autowired的属性被注入 -->
<context:component-scan base-package="com.***">
    <context:exclude-filter type="annotation" expression="org.springframework.stereotype.Controller"/>
 </context:component-scan>

<!-- 开启自动切面代理 -->
<aop:aspectj-autoproxy />

2.aspect类的编写 

@Before 进入方法打印带包路径的方法名和当前时间

@After 方法执行完打印带包路径的方法名和当前时间

@Around 大于常量的毫秒数，打印方法执行时间

@Aspect
@Component
public class LogInterceptor {
    private final Logger logger = Logger.getLogger(LogInterceptor.class);

    // 一分钟，即1000ms
    private static final long ONE_MINUTE = 1000;

    @Pointcut("execution(public * com.sully..controller..*.*(..))")
    public void myMethod(){};

    /**
     *  进入方法后打印日志
     * @param joinPoint
     */
    @Before("myMethod()")
    public void before(JoinPoint joinPoint) {
        logger.debug(this.getMethodName(joinPoint)+" start "+ DateUtil.getDateTime(new Date()));
    }

    /**
     * 方法结束打印日志
     * @param joinPoint
     */
    @After("myMethod()")
    public void after(JoinPoint joinPoint) {
        logger.debug(this.getMethodName(joinPoint)+" after"+ DateUtil.getDateTime(new Date()));
    }


    @Around("execution(* com.sully..controller..*.*(..))")
    public Object processLog(ProceedingJoinPoint joinPoint) throws Throwable {
        // 定义返回对象、得到方法需要的参数
        Object obj = null;
        Object[] args = joinPoint.getArgs();
        long startTime = System.currentTimeMillis();

        try {
            obj = joinPoint.proceed(args);
        } catch (Throwable e) {
            logger.error("统计某方法执行耗时环绕通知出错", e);
        }

        // 获取执行的方法名
        long endTime = System.currentTimeMillis();
        MethodSignature signature = (MethodSignature) joinPoint.getSignature();
        String methodName = signature.getDeclaringTypeName() + "." + signature.getName();

        // 打印耗时的信息
        this.printExecTime(methodName, startTime, endTime);

        return obj;
    }

    /**
     * 打印方法执行耗时的信息，如果超过了一定的时间，才打印
     * @param methodName
     * @param startTime
     * @param endTime
     */
    private void printExecTime(String methodName, long startTime, long endTime) {
        long diffTime = endTime - startTime;
        if (diffTime > ONE_MINUTE) {
            logger.debug( methodName + " 方法执行耗时：" + diffTime + " ms");
        }
    }

    /**
     * 获取方法名(类的详细包路径)
     * @param joinPoint
     * @return
     */
    private String getMethodName(JoinPoint joinPoint){
        return joinPoint.getSignature().getDeclaringTypeName() +
                "." + joinPoint.getSignature().getName();
    }

    /**
     * AfterReturning  拦截执行
     */
    @AfterReturning("execution(public * com.sully.finance..controller..*.*(..))")
    public void AfterReturning() {
        logger.debug("method AfterReturning");
    }

    /**
     *  AfterThrowing 拦截执行
     */
    @AfterThrowing("execution(public * com.sully.finance..controller..*.*(..))")
    public void AfterThrowing() {
        logger.debug("method AfterThrowing");
    }
}

3.步骤2中的日志打印都是debug级别，分级别输出日志就好