我的开源
SpringBoot下使用aspectJ进行性能诊断
背景
SpringBoot中的性能诊断。
本文分两个部分。先介绍SpringBoot-AOP方法，其使用方便，但是存在两个问题：
- 扩展性：不支持private方法，不支持本类内部调用的其他方法进行切面。
- 性能：继承、实现了spring的代理类和拦截器，性能相对差一些。
然后介绍原生的AspectJ方法。
SpringBoot-AOP初体验
依赖
需要添加两个依赖，版本号可以使用最新。
<dependency> <groupId>org.springframework</groupId> <artifactId>spring-aop</artifactId> <version>5.0.1.RELEASE</version> <scope>compile</scope> </dependency> <dependency> <groupId>org.aspectj</groupId> <artifactId>aspectjweaver</artifactId> <version>1.8.12</version> <scope>compile</scope> </dependency>
增加Config和Before advice
通过Config来使用AOP。
使用Before advice来打点。
@Aspect @Configuration public class UserAccessAspect { private Logger logger = LoggerFactory.getLogger(this.getClass()); //What kind of method calls I would intercept //execution(* PACKAGE.*.*(..)) //Weaving & Weaver @Before("execution(* com.in28minutes.springboot.tutorial.basics.example.aop.data.*.*(..))") public void before(JoinPoint joinPoint) { //Advice logger.info(" Check for user access "); logger.info(" Allowed execution for {}", joinPoint); } }
After advice
也可以使用After advice来打点。
@After: 在两种场景下执行 - 当一个方法成功执行或是抛出异常@AfterReturning: 只有在方法成功执行后运行@AfterThrowing: 只有在方法抛出异常后运行
@Aspect @Configuration public class AfterAopAspect { private Logger logger = LoggerFactory.getLogger(this.getClass()); @AfterReturning(value = "execution(* com.in28minutes.springboot.tutorial.basics.example.aop.business.*.*(..))", returning = "result") public void afterReturning(JoinPoint joinPoint, Object result) { logger.info("{} returned with value {}", joinPoint, result); } @After(value = "execution(* com.in28minutes.springboot.tutorial.basics.example.aop.business.*.*(..))") public void after(JoinPoint joinPoint) { logger.info("after execution of {}", joinPoint); } }
Around advice
最后介绍Around打点方式。
@Aspect @Configuration public class MethodExecutionCalculationAspect { private Logger logger = LoggerFactory.getLogger(this.getClass()); @Around("@annotation(com.in28minutes.springboot.tutorial.basics.example.aop.TrackTime)") public Object around(ProceedingJoinPoint joinPoint) throws Throwable { long startTime = System.currentTimeMillis(); Object proceed = joinPoint.proceed(); long timeTaken = System.currentTimeMillis() - startTime; logger.info("Time Taken by {} is {}", joinPoint, timeTaken); return proceed; } }
原生AspectJ初体验
依赖
<plugin> <groupId>com.github.m50d</groupId> <artifactId>aspectj-maven-plugin</artifactId> <version>1.11.1</version> <dependencies> <dependency> <groupId>org.aspectj</groupId> <artifactId>aspectjrt</artifactId> <version>1.8.9</version> </dependency> <dependency> <groupId>org.aspectj</groupId> <artifactId>aspectjtools</artifactId> <version>1.8.9</version> </dependency> </dependencies> <configuration> <complianceLevel>${maven.compiler.target}</complianceLevel> <source>${maven.compiler.target}</source> <target>${maven.compiler.target}</target> <proc>none</proc> <showWeaveInfo>true</showWeaveInfo> <verbose>true</verbose> <Xlint>ignore</Xlint> <encoding>${project.build.sourceEncoding}</encoding> <forceAjcCompile>true</forceAjcCompile> <sources/><!-- this is important!--> <weaveDirectories> <weaveDirectory>${project.build.directory}/classes</weaveDirectory> </weaveDirectories> </configuration> <executions> <execution> <phase>process-classes</phase> <goals> <goal>compile</goal> </goals> </execution> </executions> </plugin>
代码切片
import org.aspectj.lang.ProceedingJoinPoint; import org.aspectj.lang.annotation.Around; import org.aspectj.lang.annotation.Aspect; import java.util.Map; import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.atomic.AtomicLong; @Aspect public class FunctionAspect { public static final Map<String, AtomicLong> functionTimeCost = new ConcurrentHashMap<>(); public static final Map<String, AtomicLong> functionTimes = new ConcurrentHashMap<>(); @Around(value = "execution(* com.abeffect..*(..))") public Object around(ProceedingJoinPoint joinPoint) throws Throwable { // System.out.println("around execution " + joinPoint); long startTime = System.currentTimeMillis(); Object proceed = joinPoint.proceed(); long timeTaken = System.currentTimeMillis() - startTime; String key = joinPoint.toString(); functionTimeCost.putIfAbsent(key, new AtomicLong()); functionTimes.putIfAbsent(key, new AtomicLong()); functionTimeCost.get(key).addAndGet(timeTaken); functionTimes.get(key).incrementAndGet(); return proceed; } }
接口查看
import lombok.AllArgsConstructor; import lombok.Getter; import org.springframework.web.bind.annotation.GetMapping; import org.springframework.web.bind.annotation.RestController; import java.util.*; @RestController public class FunctionController { @AllArgsConstructor @Getter private class Unit { private String key; private int count; private long timeCost; private double avgTimeCost; } @GetMapping("/stat/reset") public String reset() { FunctionAspect.functionTimes.clear(); FunctionAspect.functionTimeCost.clear(); return "ok"; } @GetMapping("/stat/fun") public String fun() { List<Unit> list = new ArrayList<>(); Set<String> keys = FunctionAspect.functionTimes.keySet(); keys.retainAll(FunctionAspect.functionTimeCost.keySet()); for (String key : keys) { list.add(new Unit( key, FunctionAspect.functionTimes.get(key).intValue(), FunctionAspect.functionTimeCost.get(key).get(), 1.0 * FunctionAspect.functionTimeCost.get(key).get() / FunctionAspect.functionTimes.get(key).intValue() )); } Collections.sort(list, Comparator.comparingLong(t -> -t.timeCost)); StringBuilder builder = new StringBuilder(); builder.append("method\ttime cost\tcount\tavg time cost\n"); list.forEach(m -> { builder.append(m.key).append("\t") .append(m.timeCost).append("\t") .append(m.count).append("\t") .append(m.avgTimeCost).append("\n"); }); return builder.toString(); } }