政务网站建设原则/搜索

Java生鲜电商平台-API请求性能调优与性能监控

 

背景

在做性能分析时，API的执行时间是一个显著的指标，这里使用SpringBoot AOP的方式，通过对接口添加简单注解的方式来打印API的执行时间，进而对API性能加以评估。关于Spring AOP的配置，详见Spring Boot AOP 配置。

步骤

1. 声明注解 Time.java

/*** 时间记录annotation* 标注需要记录时间消耗的方法*/
@Target(ElementType.METHOD) @Retention(RetentionPolicy.RUNTIME) public @interface Timer { } 

2. 声明切面 TimeAspect.java

/*** 时间记录切面，收集接口的运行时间*/
@Aspect @Component public class TimeAspect { // 修正Timer注解的全局唯一限定符 @Pointcut("@annotation(com.rainlf.aop.timer.Timer)") private void pointcut() {} @Around("pointcut()") public Object around(ProceedingJoinPoint joinPoint) throws Throwable { // 获取目标Logger Logger logger = LoggerFactory.getLogger(joinPoint.getTarget().getClass()); // 获取目标类名称 String clazzName = joinPoint.getTarget().getClass().getName(); // 获取目标类方法名称 String methodName = joinPoint.getSignature().getName(); long start = System.currentTimeMillis(); logger.info( "{}: {}: start...", clazzName, methodName); // 调用目标方法 Object result = joinPoint.proceed(); long time = System.currentTimeMillis() - start; logger.info( "{}: {}: : end... cost time: {} ms", clazzName, methodName, time); return result; } } 

3. 使用时，在目标方式上加上@Timer即可。

@Timer
public void test() { // do something ... } 

备注

如果不使用AOP，可简单添加如下代码。

// 获取毫秒数
long startTime = System.currentTimeMillis();   //获取开始时间
System.out.println("Start..."); doSomeThing(); //测试的代码段 long endTime = System.currentTimeMillis(); //获取结束时间 System.out.println("End... Time cost: " + (endTime - startTime) + "ms"); // 获取纳秒数 long startTime = System.nanoTime(); //获取开始时间 System.out.println("Start..."); doSomeThing(); //测试的代码段 long endTime = System.nanoTime(); //获取结束时间 System.out.println("End... Time cost: " + (endTime - startTime) + "ns");


上面是采用注解的方案，不过有人觉得注解不太好，可以换成以下方案：

import org.apache.commons.lang.time.StopWatch;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.*;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;
import javax.servlet.http.HttpServletRequest;
/*** 声明一个切面,记录每个Action的执行时间* @author administrator*/
@Aspect
@Component
public class LogAspect {private static final Logger logger=LoggerFactory.getLogger(LogAspect.class);/*** 切入点：表示在哪个类的哪个方法进行切入。配置有切入点表达式*/@Pointcut("execution(* com.Xx.xxx..controller.*.*(..))")public void pointcutExpression() {logger.debug("配置切入点");}/*** 1 前置通知* @param joinPoint*/@Before("pointcutExpression()")public void beforeMethod(JoinPoint joinPoint) {// 开始打印请求日志ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();HttpServletRequest request = attributes.getRequest();// 打印请求相关参数logger.info("===== Start ======");// 打印请求 urllogger.info("URL:{}", request.getRequestURL().toString());// 打印 Http methodlogger.info("HTTP Method:{}", request.getMethod());// 打印调用 controller 的全路径以及执行方法logger.info("Class Method:{}.{}", joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName());// 打印请求的 IPlogger.info("IP:{}", request.getRemoteAddr());//获取传入目标方法的参数logger.info("args={}",joinPoint.getArgs());}/*** 2 后置通知* 在方法执行之后执行的代码. 无论该方法是否出现异常*/@After("pointcutExpression()") public void afterMethod(JoinPoint joinPoint) {logger.debug("后置通知执行了，有异常也会执行");}/*** 3 返回通知* 在方法法正常结束受执行的代码* 返回通知是可以访问到方法的返回值的!* @param joinPoint* @param returnValue*/@AfterReturning(value = "pointcutExpression()", returning = "returnValue")public void afterRunningMethod(JoinPoint joinPoint, Object returnValue) {logger.debug("返回通知执行，执行结果：" + returnValue);}/*** 4 异常通知* 在目标方法出现异常时会执行的代码.* 可以访问到异常对象; 且可以指定在出现特定异常时在执行通知代码* @param joinPoint* @param e*/@AfterThrowing(value = "pointcutExpression()", throwing = "e")public void afterThrowingMethod(JoinPoint joinPoint, Exception e){logger.debug("异常通知, 出现异常 " + e);}/*** 环绕通知需要携带 ProceedingJoinPoint 类型的参数. * 环绕通知类似于动态代理的全过程: ProceedingJoinPoint 类型的参数可以决定是否执行目标方法.* 且环绕通知必须有返回值, 返回值即为目标方法的返回值*/@Around("pointcutExpression()")public Object aroundMethod(ProceedingJoinPoint pjd){StopWatch clock = new StopWatch();//返回的结果Object result = null;//方法名称String className=pjd.getTarget().getClass().getName();String methodName = pjd.getSignature().getName();try {// 计时开始
            clock.start(); //前置通知//执行目标方法result = pjd.proceed();//返回通知
            clock.stop();} catch (Throwable e) {//异常通知
            e.printStackTrace();}//后置通知if(!methodName.equalsIgnoreCase("initBinder")){long constTime=clock.getTime();logger.info("["+className+"]"+"-" +"["+methodName+"]"+" 花费时间： " +constTime+"ms");if(constTime>500){logger.error("["+className+"]"+"-" +"["+methodName+"]"+" 花费时间过长，请检查: " +constTime+"ms");}}return result;}
}