用System.currentTimeMillis()统计代码运行时间？说明你还是新手
用System.currentTimeMillis()统计代码运行时间？说明你还是新手
今日有人问我开发中是怎么统计代码执行时长的，在本文中，我们将介绍如何除了使用System.currentTimeMillis()方法外的其他方法。
一、Spring AOP 方式实现
Spring AOP（面向切面编程）是Spring框架的一个重要组成部分，它提供了一种非常方便的方法来实现代码的横向切面。在Spring Boot中，我们可以使用AOP来统计代码执行时间。
1.1 引入依赖
首先，我们需要在项目中引入Spring AOP的依赖，如下所示：
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-aop</artifactId>
</dependency>
1.2 编写切面类
接下来，我们需要编写一个切面类来实现代码的执行时间统计。我们可以使用@Before和@After注解来分别标记方法的前置和后置通知，从而实现代码的耗时统计。代码如下：
@Aspect
@Component
public class ExecutionTimeAspect {
private static final Logger logger = LoggerFactory.getLogger(ExecutionTimeAspect.class);
@Before("@annotation(org.springframework.web.bind.annotation.RequestMapping)")
public void logBefore(JoinPoint joinPoint) {
logger.info("Start executing {}", joinPoint.getSignature());
}
@After("@annotation(org.springframework.web.bind.annotation.RequestMapping)")
public void logAfter(JoinPoint joinPoint) {
long executionTime = System.currentTimeMillis() - ((ServletRequestAttributes) RequestContextHolder.currentRequestAttributes()).getRequest().getAttribute("startTime");
logger.info("Finished executing {} in {}ms", joinPoint.getSignature(), executionTime);
}
@Around("@annotation(org.springframework.web.bind.annotation.RequestMapping)")
public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {
long startTime = System.currentTimeMillis();
Object proceed = joinPoint.proceed();
long endTime = System.currentTimeMillis();
ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.currentRequestAttributes();
attributes.getRequest().setAttribute("startTime", startTime);
logger.info("Execution time of {} is {}ms", joinPoint.getSignature(), (endTime - startTime));
return proceed;
}
}
在上面的代码中，我们使用了@Aspect注解来标记这个类是一个切面类，@Component注解将该类纳入Spring容器管理。在该类中，我们定义了三个方法：logBefore()、logAfter()和logExecutionTime()。
logBefore()方法使用@Before注解来标记，它会在标记了@RequestMapping注解的方法执行前被执行，用于记录日志。
logAfter()方法使用@After注解来标记，它会在标记了@RequestMapping注解的方法执行后被执行，用于记录日志和计算代码执行时间。
logExecutionTime()方法使用@Around注解来标记，它会在标记了@RequestMapping注解的方法执行前后被执行，用于记录日志和计算代码执行时间。在该方法中，我们使用了ProceedingJoinPoint来调用目标方法，并使用System.currentTimeMillis()方法记录了方法执行的开始和结束时间。最后，我们通过ServletRequestAttributes来获取当前请求的上下文，并将开始时间保存在请求的属性中。
1.3 配置AOP切面
最后，我们需要在Spring Boot的配置文件中配置AOP切面。具体来说，我们需要使用@EnableAspectJAutoProxy注解来启用AOP，以及使用@Import注解将ExecutionTimeAspect类导入到Spring容器中。配置文件如下：
@Configuration
@EnableAspectJAutoProxy
@Import(ExecutionTimeAspect.class)
public class AppConfig {
}
二、Spring Boot Interceptor 方式实现
除了使用AOP外，我们还可以使用Spring Boot自带的Interceptor来实现代码执行时间的统计。Interceptor是Spring MVC框架的一个重要组件，它可以在请求到达Controller之前或之后进行一些处理。
2.1 编写Interceptor类
在Spring Boot中，我们可以通过实现HandlerInterceptor接口来编写自定义的Interceptor类。具体来说，我们需要实现preHandle()和postHandle()方法，在这两个方法中分别记录代码执行的开始和结束时间，并计算代码的执行时间。代码如下：
@Component
public class ExecutionTimeInterceptor implements HandlerInterceptor {
private static final Logger logger = LoggerFactory.getLogger(ExecutionTimeInterceptor.class);
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
request.setAttribute("startTime", System.currentTimeMillis());
logger.info("Start executing {}", handler);
return true;
}
@Override
public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception {
long startTime = (long) request.getAttribute("startTime");
long endTime = System.currentTimeMillis();
logger.info("Finished executing {} in {}ms", handler, (endTime - startTime));
}
}
在上面的代码中，我们实现了HandlerInterceptor接口，并重写了preHandle()和postHandle()方法。在preHandle()方法中，我们使用ServletRequest的setAttribute()方法记录了方法执行的开始时间，并使用Logger记录了日志。在postHandle()方法中，我们使用ServletRequest的getAttribute()方法获取了开始时间，并使用Logger记录了日志和计算了代码执行时间。
2.2 配置Interceptor
接下来，我们需要在Spring Boot的配置文件中配置Interceptor。具体来说，我们需要继承WebMvcConfigurerAdapter并重写addInterceptors()方法，将ExecutionTimeInterceptor注册到Interceptor链中。代码如下：
@Configuration
public class WebMvcConfig extends WebMvcConfigurerAdapter {
@Autowired
private ExecutionTimeInterceptor executionTimeInterceptor;
@Override
public void addInterceptors(InterceptorRegistry registry) {
registry.addInterceptor(executionTimeInterceptor);
}
}
在上面的代码中，我们继承了WebMvcConfigurerAdapter类，并重写了addInterceptors()方法。在该方法中，我们使用@Autowired注解将ExecutionTimeInterceptor注入到配置类中，并将它添加到Interceptor链中。
三、Spring Boot Actuator Metrics 方式实现
除了使用AOP和Interceptor外，我们还可以使用SpringBoot Actuator的Metrics功能来实现代码执行时间的统计。Spring Boot Actuator是Spring Boot的一个子项目，它提供了一些监控和管理Spring Boot应用程序的功能，包括健康检查、度量指标、环境配置、日志记录和审计等。
3.1 引入Actuator依赖
首先，我们需要在pom.xml文件中引入Spring Boot Actuator的依赖。具体来说，我们需要添加以下依赖：
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-actuator</artifactId>
</dependency>
3.2 配置Metrics
接下来，我们需要在Spring Boot的配置文件中配置Metrics。具体来说，我们需要设置metrics.enable=true来启用Metrics，以及设置metrics.filter.include.*=execution.time.*来将所有以execution.time开头的指标添加到Metrics中。代码如下：
management:
endpoints:
web:
exposure:
include: "*"
metrics:
enable: true
filter:
include:
"*": execution.time.*
3.3 编写执行时间统计方法
接下来，我们需要编写一个统计执行时间的方法，并将它添加到Metrics中。具体来说，我们需要在该方法中使用Timer来记录方法执行的时间，并使用MeterRegistry将时间添加到Metrics中。代码如下：
@Service
public class ExecutionTimeService {
private final Timer executionTimer;
public ExecutionTimeService(MeterRegistry meterRegistry) {
this.executionTimer = meterRegistry.timer("execution.time");
}
public <T> T time(String name, Supplier<T> supplier) {
Timer.Sample sample = Timer.start();
try {
return supplier.get();
} finally {
sample.stop(executionTimer.tag("name", name));
}
}
}
在上面的代码中，我们定义了一个ExecutionTimeService类，并在构造函数中使用MeterRegistry创建了一个名为execution.time的Timer。在time()方法中，我们使用Timer.Sample.start()方法记录方法执行的开始时间，并使用Timer.Sample.stop()方法记录方法执行的结束时间，并将方法名和时间添加到Metrics中。
3.4 使用执行时间统计方法
最后，我们需要在代码中使用ExecutionTimeService来统计方法的执行时间。具体来说，我们可以在需要统计执行时间的方法中使用ExecutionTimeService的time()方法，并传入方法名和方法执行的代码块。代码如下：
@RestController
public class HelloController {
@Autowired
private ExecutionTimeService executionTimeService;
@GetMapping("/hello")
public String hello() {
return executionTimeService.time("hello", () -> {
try {
Thread.sleep(1000);
} catch (InterruptedException e) {
e.printStackTrace();
}
return "Hello, World!";
});
}
}
在上面的代码中，我们在HelloController中注入了ExecutionTimeService，并在hello()方法中使用ExecutionTimeService的time()方法来统计方法的执行时间。具体来说，我们传入了方法名"hello"和一个Lambda表达式，该表达式中执行了一个休眠1秒的操作，并返回"Hello, World!"。
四、“StopWatch实现
当我们需要测量代码执行时间时，Spring Framework 提供了一个非常方便的工具类——StopWatch。
StopWatch类是Spring Framework中的一个计时器，它可以用于测量程序中代码执行的时间，而无需进行任何配置。StopWatch记录从开始到停止的时间，并提供了一些方便的方法来帮助我们更好地理解测量结果。
下面是一个示例，展示如何使用StopWatch类来测量代码执行时间：
import org.springframework.util.StopWatch;
public class MyService {
public void doSomething() {
StopWatch stopWatch = new StopWatch();
stopWatch.start();
// 需要被测量的代码
// ...
stopWatch.stop();
System.out.println("代码执行时间：" + stopWatch.getTotalTimeMillis() + " 毫秒");
}
}
在上面的示例中，我们首先创建了一个StopWatch对象，并调用了它的start()方法来启动计时器。然后在需要被测量的代码前面添加了一些代码，执行完需要被测量的代码后，我们再调用StopWatch对象的stop()方法来停止计时器。最后，我们通过调用getTotalTimeMillis()方法来获取代码执行时间，并将其输出到控制台。
需要注意的是，StopWatch类只是一个计时器，并不能像AOP、拦截器和Metrics功能一样对具体的请求进行统计。因此，如果我们需要对具体的请求进行统计，就需要结合其他技术来实现。但是，如果只需要简单地测量代码执行时间，StopWatch类是一个非常方便和实用的工具。
五、总结
在本文中，我们介绍了如何使用多种方式来实现Spring Boot应用程序中代码执行时间的统计。具体来说，我们介绍了使用AOP、拦截器、和Spring Boot Actuator的Metrics功能三种方式来实现代码执行时间的统计。
使用AOP的方式可以帮助我们快速地实现代码执行时间的统计，但需要对AOP的概念和实现方式有一定的了解。使用拦截器的方式相对来说更加灵活，可以针对具体的请求进行统计，但需要手动编写拦截器的代码。使用Spring Boot Actuator的Metrics功能可以方便地将执行时间添加到Metrics中，并可以通过Spring Boot Actuator的监控端点查看Metrics的统计结果。
无论使用哪种方式，代码执行时间的统计都可以帮助我们识别性能瓶颈，优化应用程序的性能。在实际开发中，我们可以根据具体的场景选择合适的方式来实现代码执行时间的统计。
本文只是对代码执行时间的统计进行了简单的介绍，如果读者对Spring Boot、AOP、拦截器和Spring Boot Actuator等技术有深入的了解，可以进一步深入研究这些技术的细节和更高级的应用场景。
