使用SpringBoot开发时通过Spring的Stopwatch定位执行时间慢的代码
日常检查业务系统功能时发现系统的一个首页访问慢,大概看了下代码,业务代码非常多,需要快速定位哪段代码执行速度慢,因此网上搜索了资料,采用较多的是使用Spring的stopwatch工具类,因此,结合此工具类,采用aop方式实现定位访问时间慢的代码。
1.编写StopWatchAspect的AOP类
package cn.gzsendi;
import java.lang.reflect.Method;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.Signature;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.aspectj.lang.reflect.MethodSignature;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import org.springframework.util.StopWatch;
@Aspect
@Component
public class StopWatchAspect {
//指定用name为ERROR的logback配置记录日志
private Logger logger = LoggerFactory.getLogger("ERROR");
//指定记录cn.gzsendi.modules.biz包下的所有方法的执行时间
@Pointcut("execution(public * cn.gzsendi.modules.biz..*.*(..))")
public void controllerPoint() {
}
@Pointcut("controllerPoint()")
public void excudeService() {
}
@Around("excudeService()")
public Object doAround(ProceedingJoinPoint pjp) throws Throwable {
Signature sig = pjp.getSignature();
//类名
String className = pjp.getSignature().getDeclaringTypeName();
// 方法名称
MethodSignature msig = (MethodSignature) sig;
Object target = pjp.getTarget();
Method currentMethod = target.getClass().getMethod(msig.getName(), msig.getParameterTypes());
String methodName = currentMethod.getName();
// 创建一个计时器
StopWatch watch = new StopWatch();
// 计时器开始
watch.start(className + "->" +methodName );
// 执行方法
Object object = pjp.proceed();
// 计时器停止
watch.stop();
logger.info(watch.prettyPrint());
return object;
}
}
2.修改logback文件配置
为了不影响其他日志的影响,因此将日志记录到独立的ERROR配置中,如上代码中的也有提及。
//指定用name为ERROR的logback配置记录日志
private Logger logger = LoggerFactory.getLogger("ERROR");
在logback.xml中增加以下配置:
<appender name="ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${log_path}error.log</file>
<rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
<fileNamePattern>${log_path}error.log.%i</fileNamePattern>
<minIndex>1</minIndex>
<maxIndex>10</maxIndex>
</rollingPolicy>
<triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
<maxFileSize>10MB</maxFileSize>
</triggeringPolicy>
<encoder>
<pattern>%d %5p [%t] %c.%M:%L - %m%n</pattern>
</encoder>
</appender>
<logger name="ERROR" additivity="false" level="INFO">
<appender-ref ref="STDOUT" />
<appender-ref ref="ERROR"/>
</logger>
3.将StopWatchAspect.java放在springboot启动类的同级目录下
4.启动Springboot工程(略)
5. 通过curl命令调用接口测试
通过curl调用接口(也可采用postman或jemeter),我未装这些软件,就直接使用git安装后自带的bash来执行了
$ curl -X POST -H 'Content-Type:application/json' -H 'token:loginuser_c57f6eae706842d1a80fec9e3f2ca07d' "http://127.0.0.1:16030/customerService/totalview" -d '{"data":{"beginTime":"2021-02-14 00:00:00","endTime":"2021-02-14 23:59:59"}}'
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 76 0 0 100 76 0 8 0:00:09 0:00:09 --:--:--
可以看到代码执行用了9秒
7. 查看结果
可以清楚的看到哪个类的哪个方法执行了多少毫秒等,因此可以进一步进行查看代码定位了。