SpringBoot中的7种耗时统计的实现方法与应用场景

public void doSomething() {
    long start = System.currentTimeMillis();

    // 模拟业务逻辑
    try {
        Thread.sleep(100);
    } catch (InterruptedException e) {
        Thread.currentThread().interrupt();
    }

    long end = System.currentTimeMillis();
    System.out.println("方法执行耗时：" + (end - start) + "ms");
}

import org.springframework.util.StopWatch;

public void processUserFlow() {
    StopWatch stopWatch = new StopWatch("用户处理流程");

    stopWatch.start("查询用户");
    // 查询逻辑...
    Thread.sleep(50);
    stopWatch.stop();

    stopWatch.start("更新缓存");
    // 缓存操作...
    Thread.sleep(80);
    stopWatch.stop();

    log.info(stopWatch.prettyPrint());
}

@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface LogCostTime {
    String value() default ""; // 方法描述
    long threshold() default 0; // 耗时阈值（ms），超过则告警
}

@Aspect
@Component
@Slf4j
@Order(1) // 确保优先级
public class CostTimeAspect {

    @Around("@annotation(logCostTime)")
    public Object around(ProceedingJoinPoint pjp, LogCostTime logCostTime) throws Throwable {
        String methodName = pjp.getSignature().getName();
        String desc = logCostTime.value();
        long threshold = logCostTime.threshold();

        long start = System.nanoTime(); // 高精度计时
        Object result;
        try {
            result = pjp.proceed();
        } finally {
            long costNanos = System.nanoTime() - start;
            long costMillis = TimeUnit.NANOSECONDS.toMillis(costNanos);

            // 根据阈值决定日志级别
            if (threshold > 0 && costMillis > threshold) {
                log.warn("方法: {}.{}({}) 耗时超阈值: {} ms (阈值: {} ms)", 
                         pjp.getTarget().getClass().getSimpleName(), methodName, desc, costMillis, threshold);
            } else {
                log.info("方法: {}.{}({}) 耗时: {} ms", 
                         pjp.getTarget().getClass().getSimpleName(), methodName, desc, costMillis);
            }
        }
        return result;
    }
}

@Service
public class UserService {

    @LogCostTime(value = "根据ID查询用户", threshold = 50)
    public User getUserById(Long id) {
        try {
            Thread.sleep(100); // 模拟耗时
        } catch (InterruptedException e) {
            Thread.currentThread().interrupt();
        }
        return userRepository.findById(id);
    }
}

<dependency>
    <groupId>io.micrometer</groupId>
    <artifactId>micrometer-core</artifactId>
</dependency>
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-actuator</artifactId>
</dependency>

management:
  endpoints:
    web:
      exposure:
        include: metrics, prometheus
  metrics:
    export:
      prometheus:
        enabled: true

@Service
public class BusinessService {

    @Timed(
        value = "business.process.time",
        description = "业务处理耗时",
        percentiles = {0.5, 0.95, 0.99}
    )
    public void process() {
        try {
            Thread.sleep(200);
        } catch (InterruptedException e) {
            Thread.currentThread().interrupt();
        }
    }
}

# HELP business_process_time_seconds  
# TYPE business_process_time_seconds summary
business_process_time_seconds_count{method="process",} 1.0
business_process_time_seconds_sum{method="process",} 0.201

public void doSomething() {
    Instant start = Instant.now();

    // 业务逻辑
    try {
        Thread.sleep(150);
    } catch (InterruptedException e) {
        Thread.currentThread().interrupt();
    }

    Instant end = Instant.now();
    Duration duration = Duration.between(start, end);
    log.info("耗时：{} ms", duration.toMillis());
}

public CompletableFuture<Void> asyncProcess() {
    long start = System.nanoTime();

    return CompletableFuture.runAsync(() -> {
        // 模拟异步任务
        try {
            Thread.sleep(100);
        } catch (InterruptedException e) {
            Thread.currentThread().interrupt();
        }
    }).whenComplete((result, ex) -> {
        long cost = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - start);
        log.info("异步任务耗时：{} ms", cost);
    });
}

@Component
public class RequestTimeInterceptor implements HandlerInterceptor {

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
        request.setAttribute("startTime", System.nanoTime());
        return true;
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) {
        Long start = (Long) request.getAttribute("startTime");
        if (start != null) {
            long costNanos = System.nanoTime() - start;
            long costMillis = TimeUnit.NANOSECONDS.toMillis(costNanos);
            String uri = request.getRequestURI();
            log.info("HTTP {} {} 耗时: {} ms", request.getMethod(), uri, costMillis);
        }
    }
}

@Configuration
public class WebConfig implements WebMvcConfigurer {
    @Autowired
    private RequestTimeInterceptor requestTimeInterceptor;

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(requestTimeInterceptor);
    }
}