执行方法栈中所有方法所花费的时间

Question

很多时候在编写应用程序时，我希望在 stacktrace 中分析和测量所有方法所花费的时间。我的意思是说：

Method A --> Method B --> Method C ...

A 方法在内部调用 B 并且它可能会调用另一个。我想知道在每个方法中执行所花费的时间。这样在一个web应用中，我可以准确的知道哪部分代码消耗了多少时间。

为了进一步解释，大多数时候在 spring 应用程序中，我编写了一个方面来收集 class 的每个方法调用的信息。最后给了我总结。但我讨厌这样做，它重复且冗长，并且需要不断更改正则表达式以适应不同的 classes。相反，我想要这样：

@Monitor
public void generateReport(int id){
...
}

在方法上添加一些注释将触发检测 api 以收集此方法所用时间的所有统计信息以及以后调用的任何方法。并且当该方法退出时，它停止收集信息。我觉得这个应该比较容易实现。

问题是：对于一般 java 代码，是否有任何合理的替代方案可以让我这样做？或者任何快速收集这些信息的方法。甚至 spring 应用程序的 spring 插件？

PS：与 XRebel 完全一样，它会生成代码的安全、dao、服务等部分所用时间的精美摘要。但它要花一枚炸弹。如果你买得起，你一定要买。[=15=]

Answer 1

您想写一个 Java agent. Such an agent allows you to redefine a class when it is loaded. This way, you can implement an aspect without polluting your source code. I have written a library, Byte Buddy，这使这很容易。

对于您的监视器示例，您可以按如下方式使用 Byte Buddy：

new AgentBuilder.Default()
 .rebase(declaresMethod(isAnnotatedWith(Monitor.class))
 .transform( (builder, type) ->
   builder
     .method(isAnnotatedWith(Monitor.class))
     .intercept(MethodDelegation.to(MonitorInterceptor.class);
  );

class MonitorInterceptor {
  @RuntimeType
  Object intercept(@Origin String method,
                                @SuperCall Callable<?> zuper)
      throws Exception {
    long start = System.currentTimeMillis();
    try {
       return zuper.call();
     } finally {
       System.out.println(method + " took " + (System.currentTimeMillis() - start);
     }
   }
}

上面构建的代理可以安装在提供给任何 Java 代理的检测接口实例上。

作为使用 Spring 的优势，上述代理将适用于任何 Java 实例，而不仅仅是 Spring beans。

Answer 2

我不知道是否已经有一个库在做这件事，我也不能给你一个随时可用的代码。但我可以给你一个描述，你可以如何自己实现它。

首先，我假设将 AspectJ 包含到您的项目中没有问题。比创建注释 f.e。 @Monitor 充当您喜欢的时间测量的标记。比创建一个简单的数据结构来保存您想要跟踪的信息。一个例子如下：

public class OperationMonitoring {
    boolean active=false;
    List<MethodExecution> methodExecutions = new ArrayList<>();
}

public class MethodExecution {
    MethodExcecution invoker;
    List<MethodExeuction> invocations = new ArrayList<>();
    long startTime;
    long endTime;
}

然后为所有方法创建 Around 建议。执行时检查调用的方法是否使用您的 Monitoring 注释进行注释。如果是，则开始监视该线程中的每个方法执行。一个简单的示例代码可能如下所示：

@Aspect
public class MonitoringAspect {

    private ThreadLocal<OperationMonitoring> operationMonitorings = new ThreadLocal<>();

    @Around("execution(* *.*(..))")
    public void monitoring(ProceedingJoinPoint pjp) {  
        Method method = extractMethod(pjp);
        if (method != null) {
            OperationMonitoring monitoring = null;
            if(method.isAnnotationPresent(Monitoring.class){
                 monitoring = operationMonitorings.get();
                 if(monitoring!=null){
                     if(!monitoring.active) {
                          monitoring.active=true;
                     }
                 } else {
                     // Create new OperationMonitoring object and set it
                 }
            }
            if(monitoring == null){
                 // this method is not annotated but is the tracking already active?
                 monitoring = operationMonitoring.get();
            }
            if(monitoring!=null && monitoring.active){
               // do monitoring stuff and invoke the called method
            } else {
               // invoke the called method without monitoring
            }
            // Stop the monitoring by setting monitoring.active=false if this method was annotated with Monitoring (and it started the monitoring).
        }
    }


    private Method extractMethod(JoinPoint joinPoint) {
         if (joinPoint.getKind().equals(JoinPoint.METHOD_EXECUTION) && joinPoint.getSignature() instanceof MethodSignature) {
              return ((MethodSignature) joinPoint.getSignature()).getMethod();
         }
         return null;
    }
}

上面的代码只是一个操作方法。我也会重组代码，但我已经将它写在文本字段中，所以请注意架构缺陷。正如最后的评论所提到的。此解决方案不支持沿途使用多个带注释的方法。但是添加这个很容易。这种方法的局限性在于，当您在跟踪路径中启动其他线程时，它会失败。添加对在受监视线程中启动新线程的支持并不那么容易。这也是为什么 IoC 框架具有自己的处理线程的功能以能够对其进行跟踪的原因。

我希望你能理解这个的一般概念，如果不明白，请随时提出进一步的问题。

Answer 3

你说你想知道堆栈上每个例程所用时间的百分比。

我假设你的意思是包括时间。

我还假设你的意思是 wall-clock 时间，理论上如果那些较低级别的被调用者之一碰巧做了一些 I/O，锁定等., 你不想对此视而不见。

因此，按挂钟时间采样的堆栈采样分析器将获得正确的信息。

A占用的时间百分比是包含A的样本的百分比，B同理，以此类推

要得到A的时间被B使用的百分比，就是包含A的样本恰好在下一级有B的百分比。

信息都在堆栈示例中，但可能很难让探查器只提取您想要的信息。

您还说您想要精确百分比。这意味着您还需要大量堆栈样本。例如，如果您想将测量的不确定性缩小 10 倍，则需要 100 倍的样本。

根据我发现性能问题的经验，我愿意容忍 10% 或更多的不确定性，因为我的目标是找到大的浪费，而不是精确地知道它有多糟糕。所以我手动取样，然后手动查看它们。事实上，如果你看一下统计数据，你只需要在两个个样本上看到一些浪费的东西就知道它是坏的，而且你在看到它两次之前采取的样本越少，更糟的是。（示例：如果问题浪费了 30% 的时间，平均需要 2/30% = 6.67 个样本才能看到它两次。如果它浪费了 90% 的时间，平均只需要 2.2 个样本。）

Answer 4

这就是我构建开源工具 stagemonitor, which uses Byte Buddy to insert profiling code. If you want to monitor a web application you don't have to alter or annotate your code. If you have a standalone application, there is a @MonitorRequests 您可以使用的注释的确切原因。

执行方法栈中所有方法所花费的时间

Time taken to execute all methods in a method stack

java

spring

profiling