现在有这样一种常见,系统中有一个接口,该接口执行的方法忽快忽慢,因此你需要去统计改方法的执行时间。刚开始你的代码可能如下:
long start = System.currentTimeMillis(); somemethod(); long end = System.currentTimeMillis(); System.out.println(end-start);
这个方式能够打印方法执行的时间,可是疑问来了,如果系统中很多方法都需要计算时间,都需要重复这样的代码?这个时候,你可以考虑注解,通过aop去计时。
在项目中添加如下依赖:
<?xml version="1.0" encoding="UTF-8"?> <project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd"> <modelVersion>4.0.0</modelVersion> <parent> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-parent</artifactId> <version>2.1.4.RELEASE</version> <relativePath/> <!-- lookup parent from repository --> </parent> <groupId>com.example</groupId> <artifactId>demo</artifactId> <version>0.0.1-SNAPSHOT</version> <name>demo</name> <description>Demo project for Spring Boot</description> <properties> <java.version>1.8</java.version> </properties> <dependencies> <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-actuator</artifactId> </dependency> <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-aop</artifactId> </dependency> <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-web</artifactId> </dependency> <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-test</artifactId> <scope>test</scope> </dependency> </dependencies> <build> <plugins> <plugin> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-maven-plugin</artifactId> </plugin> </plugins> </build> </project>
定义一个注解MethodStats,所有加上此注解的方法可以打印方法执行的时间。
package com.example.demo; import java.lang.annotation.ElementType; import java.lang.annotation.Retention; import java.lang.annotation.RetentionPolicy; import java.lang.annotation.Target; @Retention(RetentionPolicy.RUNTIME) @Target(ElementType.METHOD) public @interface MethodStats { }
定义一个拦截类,通过此拦截类,可以统计有注解的方法的执行时间。
package com.example.demo; import org.aspectj.lang.ProceedingJoinPoint; import org.aspectj.lang.annotation.Around; import org.aspectj.lang.annotation.Aspect; import org.aspectj.lang.reflect.MethodSignature; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.springframework.context.annotation.ComponentScan; import org.springframework.stereotype.Component; @Aspect @Component public class TimeLogger { Logger logger = LoggerFactory.getLogger(getClass()); @Around("@annotation(com.example.demo.MethodStats)") public Object log(ProceedingJoinPoint point) throws Throwable { long start = System.currentTimeMillis(); Object result = point.proceed(); logger.info("className={}, methodName={}, timeMs={},threadId={}",new Object[]{ MethodSignature.class.cast(point.getSignature()).getDeclaringTypeName(), MethodSignature.class.cast(point.getSignature()).getMethod().getName(), System.currentTimeMillis() - start, Thread.currentThread().getId()} ); return result; } }
下面是一个测试:
package com.example.demo; import org.springframework.web.bind.annotation.GetMapping; import org.springframework.web.bind.annotation.RestController; @RestController public class HelloController { // 防在这里可以拦截 @GetMapping("/") @MethodStats public String hello2() { return "hello2"; } }
现在假设,我们需要方法必须在一定时间内执行完,如果没有执行完强制返回,我们现在就需要给注解添加一个时间的变量。
@Retention(RetentionPolicy.RUNTIME) @Target(ElementType.METHOD) public @interface MethodStats { public int time() default -1; }
相应的拦截器的方法做如下处理:
package com.example.demo; import java.util.concurrent.Callable; import java.util.concurrent.ExecutionException; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; import java.util.concurrent.Future; import java.util.concurrent.TimeUnit; import java.util.concurrent.TimeoutException; import javax.rmi.CORBA.Tie; import org.aspectj.lang.ProceedingJoinPoint; import org.aspectj.lang.annotation.Around; import org.aspectj.lang.annotation.Aspect; import org.aspectj.lang.reflect.MethodSignature; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.springframework.context.annotation.ComponentScan; import org.springframework.stereotype.Component; @Aspect @Component public class TimeLogger { Logger logger = LoggerFactory.getLogger(getClass()); @Around("@annotation(com.example.demo.MethodStats)") public Object log(ProceedingJoinPoint point) throws Throwable { long start = System.currentTimeMillis(); int time = MethodSignature.class.cast(point.getSignature()).getMethod().getAnnotation(MethodStats.class).time(); if (time > 0) { ExecutorService executor = Executors.newSingleThreadExecutor(); Future<Object> future = executor.submit(new Callable<Object>() { public Object call() throws Exception { Object result = null; try { result = point.proceed(); } catch (Throwable e) { // TODO Auto-generated catch block e.printStackTrace(); } return result; } }); try { future.get(time, TimeUnit.SECONDS); } catch (InterruptedException | ExecutionException | TimeoutException e) { // do something or log it } finally { future.cancel(true); logger.info("cancel"); } } else { Object result = point.proceed(); logger.info("className={}, methodName={}, timeMs={},threadId={}", new Object[] { MethodSignature.class.cast(point.getSignature()).getDeclaringTypeName(), MethodSignature.class.cast(point.getSignature()).getMethod().getName(), System.currentTimeMillis() - start, Thread.currentThread().getId() }); return result; } return null; } }
主要思路使用Future去控制方法的执行时间,上述样例仅供学习测试,如果在线上环境,请使用hystrix,hystrix提供了晚上的failback。需要特别注意的是,spring 的事务提供了timeout的注解,可以控制事务的执行时间。