我的开源
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();
}
}