使用SpringBoot开发时通过Spring的Stopwa

使用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. 查看结果

可以清楚的看到哪个类的哪个方法执行了多少毫秒等，因此可以进一步进行查看代码定位了。