Java生鮮電商平台-API請求性能調優與性能監控

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 ======");
        // 打印請求 url
        logger.info("URL:{}", request.getRequestURL().toString());
        // 打印 Http method
        logger.info("HTTP Method:{}", request.getMethod());
        // 打印調用 controller 的全路徑以及執行方法
        logger.info("Class Method:{}.{}", joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName());
        // 打印請求的 IP
        logger.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;
    }
}