Spring-Boot+AOP+统计单次请求方法的执行次数和耗时情况

谁践踏了优雅 2022-12-01 14:01 526阅读 0赞

参考文章：[Spring-Boot+AOP+统计单次请求方法的执行次数和耗时情况][Spring-Boot_AOP]

[SpringBoot（审计） 统计接口调用次数及成功率][SpringBoot_]

# ControllerInterceptor  #

package com.fiend.ou.cdp.monitorcollect.aspect;
    
    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 java.util.HashMap;
    import java.util.Map;
    
    /**
     * @author langpf
     */
    @Aspect
    @Component
    public class WebQueryAespect {
        private final Logger log = LoggerFactory.getLogger(getClass());
    
        //ThreadLocal 维护变量 避免同步
        //ThreadLocal为每个使用该变量的线程提供独立的变量副本，所以每一个线程都可以独立地改变自己的副本，而不会影响其它线程所对应的副本。
        ThreadLocal<Long> startTime = new ThreadLocal<>();// 开始时间
    
        /**
         * map1存放方法被调用的次数O
         */
        ThreadLocal<Map<String, Long>> methodCalledNumMap = new ThreadLocal<>();
    
        /**
         * map2存放方法总耗时
         */
        ThreadLocal<Map<String, Long>> methodCalledTimeMap = new ThreadLocal<>();
    
        /**
         * 定义一个切入点. 解释下：
         * <p>
         * ~ 第一个 * 代表任意修饰符及任意返回值. ~ 第二个 * 定义在web包或者子包 ~ 第三个 * 任意方法 ~ .. 匹配任意数量的参数.
         */
        static final String pCutStr = "execution(public * com.fiend.*..*(..))";
    
        @Pointcut(value = pCutStr)
        public void logPointcut() {
        }
    
        /**
         * Aop：环绕通知 切整个包下面的所有涉及到调用的方法的信息
         * @param joinPoint jp
         * @return o
         * @throws Throwable t
         */
        @Around("logPointcut()")
        public Object doAround(ProceedingJoinPoint joinPoint) throws Throwable {
            //初始化 一次
            if (methodCalledNumMap.get() == null) {
                methodCalledNumMap.set(new HashMap<>());
            }
    
            if (methodCalledTimeMap.get() == null) {
                methodCalledTimeMap.set(new HashMap<>());
            }
    
            long start = System.currentTimeMillis();
            try {
                Object result = joinPoint.proceed();
                if (result == null) {
                    //如果切到了 没有返回类型的void方法，这里直接返回
                    return null;
                }
                long end = System.currentTimeMillis();
    
                log.info("===================");
                String targetClassName = joinPoint.getSignature().getDeclaringTypeName();
                String methodName      = joinPoint.getSignature().getName();
    
                Object[] args = joinPoint.getArgs();// 参数
                int argsSize = args.length;
                String argsTypes = "";
                String typeStr = joinPoint.getSignature().getDeclaringType().toString().split(" ")[0];
                String returnType = joinPoint.getSignature().toString().split(" ")[0];
                log.info("类/接口:" + targetClassName + "(" + typeStr + ")");
                log.info("方法:" + methodName);
                log.info("参数个数:" + argsSize);
                log.info("返回类型:" + returnType);
                if (argsSize > 0) {
                    // 拿到参数的类型
                    for (Object object : args) {
                        argsTypes += object.getClass().getTypeName().toString() + " ";
                    }
                    log.info("参数类型：" + argsTypes);
                }
    
                Long total = end - start;
                log.info("耗时: " + total + " ms!");
    
                if (methodCalledNumMap.get().containsKey(methodName)) {
                    Long count = methodCalledNumMap.get().get(methodName);
                    methodCalledNumMap.get().remove(methodName);//先移除，在增加
                    methodCalledNumMap.get().put(methodName, count + 1);
    
                    count = methodCalledTimeMap.get().get(methodName);
                    methodCalledTimeMap.get().remove(methodName);
                    methodCalledTimeMap.get().put(methodName, count + total);
                } else {
                    methodCalledNumMap.get().put(methodName, 1L);
                    methodCalledTimeMap.get().put(methodName, total);
                }
    
                return result;
            } catch (Throwable e) {
                long end = System.currentTimeMillis();
                log.info("====around " + joinPoint + "\tUse time : " + (end - start) + " ms with exception : "
                        + e.getMessage());
                throw e;
            }
    
        }
    
        //对Controller下面的方法执行前进行切入，初始化开始时间
        @Before(value = "execution(public * com.fiend.*.controller.*.*(..))")
        public void beforeMethod(JoinPoint jp) {
            startTime.set(System.currentTimeMillis());
        }
    
        //对Controller下面的方法执行后进行切入，统计方法执行的次数和耗时情况
        //注意，这里的执行方法统计的数据不止包含Controller下面的方法，也包括环绕切入的所有方法的统计信息
        @AfterReturning(value = "execution(* com.fiend.*.controller.*.*(..))")
        public void afterMethod(JoinPoint jp) {
            long end = System.currentTimeMillis();
            long total = end - startTime.get();
            String methodName = jp.getSignature().getName();
            log.info("连接点方法为：" + methodName + ",执行总耗时为：" + total + "ms");
    
            //重新new一个map
            Map<String, Long> map = new HashMap<>();
    
            //从map2中将最后的 连接点方法给移除了，替换成最终的，避免连接点方法多次进行叠加计算
            //由于map2受ThreadLocal的保护，这里不支持remove，因此，需要单开一个map进行数据交接
            for (Map.Entry<String, Long> entry : methodCalledTimeMap.get().entrySet()) {
                if (entry.getKey().equals(methodName)) {
                    map.put(methodName, total);
    
                } else {
                    map.put(entry.getKey(), entry.getValue());
                }
            }
    
            for (Map.Entry<String, Long> entry : methodCalledNumMap.get().entrySet()) {
                for (Map.Entry<String, Long> entry2 : map.entrySet()) {
                    if (entry.getKey().equals(entry2.getKey())) {
                        System.err.println(entry.getKey() + ",被调用次数：" + entry.getValue() + ",综合耗时：" + entry2.getValue() + "ms");
                    }
                }
    
            }
        }
    }

# 2. 统计接口调用次数及成功率 #

> **介绍：**  
> 　　很多时候会需要提供一些统计记录的，比如某个服务一个月的被调用量、接口的调用次数、成功调用次数等等。  
> **优点：**  
> 　　使用AOP+Hendler对业务逻辑代码无侵入，完全解耦。通过spring boot自带的健康检查接口（/health）方便、安全。  
> **注意：**  
> 　　数据没有被持久化，只保存在内存中，重启后数据将被重置。可按需自己实现   
> **代码：**  
> 　　AOP:在AOP中调用Handler

## 2.1 ControllerAdvice ##

@Component
    @Aspect
    public class ControllerAdvice {
      private static ILogger log = LoggerFactory.getLogger(ControllerAdvice.class);
    
      @Around("execution(public * *..*controller.*.*(..))")
      public Object handle(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
        Object result;
        try {
          Function<ProceedingJoinPoint, AbstractControllerHandler> build = AbstractControllerHandler.getBuild();
          if (null == build) {
            AbstractControllerHandler.registerBuildFunction(DefaultControllerHandler::new);
          }
          build = AbstractControllerHandler.getBuild();
          AbstractControllerHandler controllerHandler = build.apply(proceedingJoinPoint);
          if (null == controllerHandler) {
            log.warn(String.format("The method(%s) do not be handle by controller handler.", proceedingJoinPoint.getSignature().getName()));
            result = proceedingJoinPoint.proceed();
          } else {
            result = controllerHandler.handle();
          }
        } catch (Throwable throwable) {
          RuntimeHealthIndicator.failedRequestCount++;
          log.error(new Exception(throwable), "Unknown exception- -!");
    
          throw throwable;
        }
    
        return result;
      }
    }

## 2.2 Handler:执行记录的逻辑 ##

### 2.2.1 抽象类：AbstractControllerHandler  ###

public abstract class AbstractControllerHandler {
      private static ILogger log = LoggerFactory.getLogger(AbstractControllerHandler.class);
    
      private static Function<ProceedingJoinPoint, AbstractControllerHandler> build;
    
      public static Function<ProceedingJoinPoint, AbstractControllerHandler> getBuild() {
        return build;
      }
    
      public static void registerBuildFunction(Function<ProceedingJoinPoint, AbstractControllerHandler> build) {
        Assert.isNotNull(build, "build");
    
        AbstractControllerHandler.build = build;
      }
    
      protected ProceedingJoinPoint proceedingJoinPoint;
      protected HttpServletRequest httpServletRequest;
      protected String methodName;
      protected String uri;
      protected String requestBody;
      protected String ip;
      protected Method method;
      protected boolean inDataMasking;
      protected boolean outDataMasking;
    
    
      public AbstractControllerHandler(ProceedingJoinPoint proceedingJoinPoint) {
        Assert.isNotNull(proceedingJoinPoint, "proceedingJoinPoint");
    
        this.proceedingJoinPoint = proceedingJoinPoint;
        Signature signature = this.proceedingJoinPoint.getSignature();
        this.httpServletRequest = this.getHttpServletRequest(this.proceedingJoinPoint.getArgs());
        this.methodName = signature.getName();
        this.uri = null == this.httpServletRequest ? null : this.httpServletRequest.getRequestURI();
        this.requestBody = this.formatParameters(this.proceedingJoinPoint.getArgs());
        this.ip = null == this.httpServletRequest ? "" : CommonHelper.getIp(this.httpServletRequest);
        this.inDataMasking = false;
        this.outDataMasking = false;
        if (signature instanceof MethodSignature) {
          MethodSignature methodSignature = (MethodSignature) signature;
          try {
            this.method = proceedingJoinPoint.getTarget().getClass().getMethod(this.methodName, methodSignature.getParameterTypes());
            if (null != this.method) {
              LogDataMasking dataMasking = this.method.getDeclaredAnnotation(LogDataMasking.class);
              if (null != dataMasking) {
                this.inDataMasking = dataMasking.in();
                this.outDataMasking = dataMasking.out();
              }
            }
          } catch (NoSuchMethodException e) {
            e.printStackTrace();
          }
        }
      }
    
      public abstract Object handle() throws Throwable;
    
      protected void logIn() {
        String requestBody = this.requestBody;
        if (this.inDataMasking) {
          requestBody = "Data Masking";
        }
        log.info(String.format("Start-[%s][%s][%s][body: %s]", this.ip, this.uri, this.methodName, requestBody));
      }
    
      protected void logOut(long elapsedMilliseconds, boolean success, String responseBody) {
        if (success) {
          if (this.outDataMasking) {
            responseBody = "Data Masking";
          }
          log.info(
              String.format(
                  "Success(%s)-[%s][%s][%s][response body: %s]",
                  elapsedMilliseconds,
                  this.ip,
                  this.uri,
                  this.methodName,
                  responseBody));
        } else {
          log.warn(
              String.format(
                  "Failed(%s)-[%s][%s][%s][request body: %s][response body: %s]",
                  elapsedMilliseconds,
                  this.ip,
                  this.uri,
                  this.methodName,
                  this.requestBody,
                  responseBody));
        }
      }
    
      protected HttpServletRequest getHttpServletRequest(Object[] parameters) {
        try {
          if (null != parameters) {
            for (Object parameter : parameters) {
              if (parameter instanceof HttpServletRequest) {
                return (HttpServletRequest) parameter;
              }
            }
          }
    
          return ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getRequest();
        } catch (Exception e) {
          log.error(e);
    
          return null;
        }
      }
    
      protected String formatParameters(Object[] parameters) {
        if (null == parameters) {
          return null;
        } else {
          StringBuilder stringBuilder = new StringBuilder();
          for (int i = 0; i < parameters.length; i++) {
            Object parameter = parameters[i];
            if (parameter instanceof HttpServletRequest || parameter instanceof HttpServletResponse) {
              continue;
            }
    
            stringBuilder.append(String.format("[%s]: %s.", i, JSON.toJSONString(parameter)));
          }
    
          return stringBuilder.toString();
        }
      }

### 2.2.2 实现类： ###

public class DefaultControllerHandler extends AbstractControllerHandler {
      private static ILogger log = LoggerFactory.getLogger(DefaultControllerHandler.class);
      private static int currentMonth = Calendar.getInstance().get(Calendar.MONTH) + 1;
    
      public DefaultControllerHandler(ProceedingJoinPoint proceedingJoinPoint) {
        super(proceedingJoinPoint);
      }
    
      @Override
      public Object handle() throws Throwable {
        long timestamp = System.currentTimeMillis();
        this.logIn();
    
        ResponseDto responseDto;
        boolean success = false;
        try {
          Object result = proceedingJoinPoint.proceed();
          if (result instanceof ResponseDto) {
            responseDto = (ResponseDto) result;
          } else {
            responseDto = ResponseDto.success(result);
          }
          success = true;
          RuntimeHealthIndicator.successRequestCount++;
        } catch (BusinessException e) {
    //      RuntimeHealthIndicator.failedRequestCount++;
          if (this.isDebugLogLevel()) {
            log.error(e);
          }
    
          responseDto = new ResponseDto<>(e.getCode(), e.getMessage(), null);
        } catch (Exception e) {
          RuntimeHealthIndicator.failedRequestCount++;
    
          if (this.isDebugLogLevel()) {
            log.error(e);
          }
    
          responseDto = ResponseDto.failed(ExceptionDefinitions.ServerError, e.getMessage(), null);
        } finally {
          Calendar cale = Calendar.getInstance();
          if (currentMonth != (cale.get(Calendar.MONTH) + 1)) {
            String recodeKey = String.format("%d年%d月",
                cale.get(Calendar.YEAR), cale.get(Calendar.MONTH) + 1);
            String recodeValue = "successCount:" + RuntimeHealthIndicator.successRequestCount +
                " failedCount:" + RuntimeHealthIndicator.failedRequestCount;
            RuntimeHealthIndicator.historyRequestRecode.put(recodeKey, recodeValue);
            RuntimeHealthIndicator.successRequestCount = 0;
            RuntimeHealthIndicator.failedRequestCount = 0;
            currentMonth = cale.get(Calendar.MONTH);
          }
        }
    
        long duration = System.currentTimeMillis() - timestamp;
        RuntimeHealthIndicator.markRestApiInvoked(this.methodName, (int) duration);
        this.logOut(duration, success, JSON.toJSONString(responseDto));
    
        return responseDto;
      }
    
      public boolean isDebugLogLevel() {
        return log.isEnabled(LogLevel.DEBUG);
      }
    }

## 2.3 Health接口 ##

@Component
    public class RuntimeHealthIndicator extends AbstractHealthIndicator {
      private static ILogger log = LoggerFactory.getLogger(ApplicationInstanceManager.class);
      private static Map<String, RestApiInvokeStatus> restApiInvokeStatuses = new HashMap<>();
      public static long failedRequestCount = 0;
      public static long successRequestCount = 0;
    
      public static Map<String, Object> historyRequestRecode;
      private Map<String, Object> details;
    
      public RuntimeHealthIndicator() {
        this.details = new HashMap<>();
        RuntimeHealthIndicator.historyRequestRecode = new HashMap<>();
    
        this.details.put("startTime", new Date(ManagementFactory.getRuntimeMXBean().getStartTime()));
        this.details.put("path", RuntimeHealthIndicator.class.getClassLoader().getResource("").getPath());
        this.details.put("osName", System.getProperty("os.name"));
        this.details.put("osVersion", System.getProperty("os.version"));
        this.details.put("javaVersion", System.getProperty("java.version"));
        try {
          this.details.put("ip", ZGHelper.getIpV4());
        } catch (SocketException e) {
          log.error(e, "Failed to get Ipv4.");
        }
      }
    
      @Override
      protected void doHealthCheck(Health.Builder builder) throws Exception {
    
        ThreadGroup threadGroup = Thread.currentThread().getThreadGroup();
        while (null != threadGroup.getParent()) {
          threadGroup = threadGroup.getParent();
        }
        this.details.put("threadCount", threadGroup.activeCount());
        OperatingSystemMXBean operatingSystemMXBean = (OperatingSystemMXBean) ManagementFactory.getOperatingSystemMXBean();
        this.details.put("cpuUsageRate", operatingSystemMXBean.getSystemCpuLoad());
        this.details.put(
            "memoryUsageRate",
            (float) (operatingSystemMXBean.getTotalPhysicalMemorySize() - operatingSystemMXBean.getFreePhysicalMemorySize()) / (float) operatingSystemMXBean.getTotalPhysicalMemorySize());
        this.details.put("failedRequestCount", RuntimeHealthIndicator.failedRequestCount);
        this.details.put("successRequestCount", RuntimeHealthIndicator.successRequestCount);
        this.details.put("restApiInvokeStatuses", RuntimeHealthIndicator.restApiInvokeStatuses);
        this.details.put("historyRequestRecode",RuntimeHealthIndicator.historyRequestRecode);
    
        for (Map.Entry<String, Object> detail : this.details.entrySet()) {
          builder.withDetail(detail.getKey(), detail.getValue());
        }
        builder.up();
      }
    
      public static void markRestApiInvoked(String name, int duration) {
        if (StringUtils.isBlank(name)) {
          return;
        }
    
        if (!RuntimeHealthIndicator.restApiInvokeStatuses.containsKey(name)) {
          RuntimeHealthIndicator.restApiInvokeStatuses.put(name, new RestApiInvokeStatus(name));
        }
    
        RestApiInvokeStatus restApiInvokeStatus = RuntimeHealthIndicator.restApiInvokeStatuses.get(name);
        restApiInvokeStatus.setDuration(duration);
      }
    }

## 2.4 工具类 ##

public class RestApiInvokeStatus {
      private String name;
      private Date startDate;
      private Date latestDate;
      private long times;
      private float averageDuration;
      private int minDuration;
      private int maxDuration;
      private int[] durations;
    
      public String getName() {
        return name;
      }
    
      public Date getStartDate() {
        return startDate;
      }
    
      public Date getLatestDate() {
        return latestDate;
      }
    
      public long getTimes() {
        return times;
      }
    
      public int getMinDuration() {
        return minDuration;
      }
    
    
      public int getMaxDuration() {
        return maxDuration;
      }
    
      public RestApiInvokeStatus(String name) {
        Assert.isNotBlank(name, "name");
    
        this.name = name;
        this.durations = new int[1000];
        this.minDuration = Integer.MAX_VALUE;
        this.maxDuration = Integer.MIN_VALUE;
        Date now = new Date();
        this.startDate = now;
        this.latestDate = now;
    
      }
    
      public void setDuration(int duration) {
        this.durations[(int) (this.times % this.durations.length)] = duration;
        this.maxDuration = this.maxDuration > duration ? this.maxDuration : duration;
        this.minDuration = this.minDuration < duration ? this.minDuration : duration;
        this.latestDate = new Date();
        this.times++;
      }
    
      public float getAverageDuration() {
        long length = this.times < this.durations.length ? this.times : this.durations.length;
    
        int count = 0;
        for (int i = 0; i < length; i++) {
          count += this.durations[i];
        }
        this.averageDuration = (float) count / (float) length;
    
        return this.averageDuration;
      }
    }

[Spring-Boot_AOP]: https://blog.csdn.net/ruiguang21/article/details/79139373?utm_source=blogxgwz9
[SpringBoot_]: https://www.cnblogs.com/yuwenhui/p/9809671.html