通过日志监控 service 执行时间

这里通过 AOP 来实现该功能.

引入 API 依赖

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

编写切面类

package cn.mrcode.foodiedev.aspect;

import org.aopalliance.intercept.Joinpoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;

@Aspect
@Component
public class ServiceLogAspect {

    public static final Logger log =
            LoggerFactory.getLogger(ServiceLogAspect.class);

    /**
     * <pre>
     * AOP 通知：
     * 1. 前置通知：在方法调用之前执行
     * 2. 后置通知：在方法正常调用之后执行
     * 3. 环绕通知：在方法调用之前和之后，都分别可以执行的通知
     * 4. 异常通知：如果在方法调用过程中发生异常，则通知
     * 5. 最终通知：在方法调用之后执行
     * </pre>
     */

    /**
     * <pre>
     * 切面表达式：
     * execution 代表所要执行的表达式主体
     * 第一处 * 代表方法返回类型 * 代表所有类型
     * 第二处 包名代表 aop 监控的类所在的包
     * 第三处 .. 代表该包以及其子包下的所有类方法
     * 第四处 * 代表类名，* 代表所有类
     * 第五处 *(..) * 代表类中的方法名，(..)表示方法中的任何参数
     * </pre>
     *
     * @param joinPoint
     * @return
     * @throws Throwable
     */
    @Around("execution(* cn.mrcode.foodiedev.service.impl..*.*(..))")
    public Object recordTimeLog(ProceedingJoinPoint joinPoint) throws Throwable {

        log.info("====== 开始执行 {}.{} ======",
                joinPoint.getTarget().getClass(),
                joinPoint.getSignature().getName());

        // 记录开始时间
        long begin = System.currentTimeMillis();

        // 执行目标 service
        Object result = joinPoint.proceed();

        // 记录结束时间
        long end = System.currentTimeMillis();
        long takeTime = end - begin;

        if (takeTime > 3000) {
            log.error("====== 执行结束，耗时：{} 毫秒 ======", takeTime);
        } else if (takeTime > 2000) {
            log.warn("====== 执行结束，耗时：{} 毫秒 ======", takeTime);
        } else {
            log.info("====== 执行结束，耗时：{} 毫秒 ======", takeTime);
        }

        return result;
    }

}

测试信息输出

INFO  ServiceLogAspect:47 - ====== 开始执行 class cn.mrcode.foodiedev.service.impl.UserServiceImpl.queryUserForLogin ======
INFO  ServiceLogAspect:66 - ====== 执行结束，耗时：647 毫秒 ======

这里定义了：

• 耗时大于 3000 毫秒的：打印 error 日志
• 耗时大于 2000 毫秒的：打印 warn 日志
• 其他的打印 info 日志

它的作用是帮助我们在生产环境下监控 service 的运行状态，哪一个方法如果响应慢了，就能很容易的定位到。

有运维人员累积到一定程度时，就可以提交给开发人员，由开发人员去做一些针对性的优化。