关于四种获取当前执行方法名称方案的基准测试报告-51CTO.COM

本文是对作者上一篇文章中 Java 面试题之 Logback 打印日志是如何获取当前方法名称的？介绍的四种获取当前执行方法名称方案的基准测试报告。这四种方法如下，

使用 Thread.currentThread().getStackTrace() 方案
使用异常对象的 getStackTrace() 方案
使用匿名内部类的 getClass().getEnclosingMethod() 方案
Java 9 的 Stack-Walking API 方案

本文将通过使用专业基准测试工具 JMH 来对如上四种方案进行测试。

基准测试，也称之为性能测试，是一种用于衡量计算机系统，软件应用或硬件组件性能的测试方法。基准测试旨在通过运行一系列标准化的任务场景来测量系统的性能表现，从而帮助评估系统的各种指标，如响应时间、吞吐量、延迟、资源利用率等。

JMH，即 Java Microbenchmark Harness，是专门用于代码微基准测试的工具套件。何谓 Micro Benchmark 呢？简单的来说就是基于方法层面的基准测试，精度可以达到微秒级。其由 Oracle/openjdk 内部开发 JIT 编译器的大佬们所开发，作为 Java 的方法级性能测试工具可以说是非常合适的。

测试环境是作者 2018 年购买的笔记本，配置如下，

图片

重点看：

cpu：i7-8759H，6 核 12 线程
内存 16 GB（2667 MHZ）

前置准备

本文不打算做基准测试工具 JMH 的详细科普文章，有兴趣的大家自行百度 JMH 使用。所以我在这里只给大家讲解 JMH 的相关概念以及下文会用到的常用注解。

JMH 可以通过注解和配置参数来控制测试的环境和结果，例如预热次数，迭代次数，线程数，时间单位等。它还可以生成详细的测试报告，包括最小值，平均值，最大值，标准差，置信区间等。

JMH 相关概念

BeachMark：基准测试，主要用来测试一些方法的性能，可以根据不同的参数以不同的单位进行计算（可以使用平均时间作为单位，也可以使用吞吐量作为单位，可以在 BenchmarkMode 值进行调整）。
MIcro Benchmark：简单地说就是在 method 层面上的 benchmark，精度可以精确到微秒级。
OPS：Operation Per Second：每秒操作量，是衡量性能的重要指标，数值的性能越好。类似的有：TPS、QPS。
Throughput：吞吐量。
Warmup：预热，因为 JVM 的 JIT 机制的存储，如果某个函数被调用多次之后，JVM 会尝试将其编译称为机器码从而提高执行速度。为了让结果更加接近真实情况就需要进行预热。

JMH 注解介绍

@Benchmark：方法级注解，表示该方法是需要进行基准测试的对象，用法和 JUnit 的@Test类似。
@BenchmarkMode：类级或方法级注解，用来指定基准测试的模式。有以下几种模式可选：

Throughput：整体吞吐量，例如“1 秒内可以执行多少次调用”。

AverageTime：调用的平均时间，例如“每次调用平均耗时 xxx 毫秒”。

SampleTime：随机取样，最后输出取样结果的分布，例如“99%的调用在 xxx 毫秒以内，99.99%的调用在 xxx 毫秒以内”。

SingleShotTime：单次调用时间，适合用于冷启动测试，只运行一次，可以设置@Warmup(iterations = 0)来禁用预热。

All：上述所有模式的综合。

@OutputTimeUnit：类级或方法级注解，用来指定基准测试结果的时间单位，可选的有NANOSECONDS，MICROSECONDS，MILLISECONDS，SECONDS等。
@Warmup：类级或方法级注解，用来配置预热的参数，例如预热的次数，每次预热的时间，时间单位等。预热的目的是为了让 JVM 的 JIT 编译器对代码进行优化，使基准测试的结果更加接近真实情况。
@Measurement：类级或方法级注解，用来配置实际执行基准测试的参数，例如测试的轮次，每轮的时间，时间单位等。
@Threads：类级或方法级注解，用来指定每个进程中的测试线程数，可以设置为Threads.MAX来使用所有可用的线程。
@Fork：类级或方法级注解，用来指定进行 fork 的次数。如果 fork 数是 2 的话，则 JMH 会 fork 出两个进程来进行测试。

1.使用 Thread.currentThread().getStackTrace() 方法

基准测试参数配置，

Warmup: 3 iterations, 10 s each
Measurement: 5 iterations, 3 s each
Timeout: 10 min per iteration
Threads: 8 threads, will synchronize iterations
Benchmark mode: Throughput

测试代码，

需要说明的是下面的四种测试方法的 JMH 注解配置以及 main 方法都是相同的。所以为了节约篇幅，突出重点，后面三种方案将省去 JMH 注解以及 main 方法配置。

@BenchmarkMode(Mode.Throughput)
@Warmup(iterations = 3)
@Measurement(iterations = 5, time = 3, timeUnit = TimeUnit.SECONDS)
@Threads(8)
@Fork(2)
@OutputTimeUnit(TimeUnit.MILLISECONDS)
public class MethodNameTest {
    @Benchmark
    @BenchmarkMode({Mode.Throughput})
    public void m1() {
        // 获取当前方法名
        String methodName = Thread.currentThread().getStackTrace()[1].getMethodName();
    }

    public static void main(String[] args) throws RunnerException {
        Options opt = new OptionsBuilder()
                .include(MethodNameTest.class.getSimpleName())
                .build();

        new Runner(opt).run();
    }
}

测试结果，

...
# Run progress: 0.00% complete, ETA 00:06:00
# Fork: 1 of 2
# Warmup Iteration   1: 16.946 ops/ms
# Warmup Iteration   2: 17.086 ops/ms
# Warmup Iteration   3: 17.116 ops/ms
Iteration   1: 17.159 ops/ms
Iteration   2: 17.118 ops/ms
Iteration   3: 17.279 ops/ms
Iteration   4: 17.329 ops/ms
Iteration   5: 17.241 ops/ms

# Run progress: 12.50% complete, ETA 00:05:23
# Fork: 2 of 2
# Warmup Iteration   1: 16.546 ops/ms
# Warmup Iteration   2: 17.340 ops/ms
# Warmup Iteration   3: 17.431 ops/ms
Iteration   1: 17.331 ops/ms
Iteration   2: 17.099 ops/ms
Iteration   3: 17.280 ops/ms
Iteration   4: 17.511 ops/ms
Iteration   5: 17.323 ops/ms


Result "ltd.newbee.mall.MethodNameTest.m1":
  17.267 ±(99.9%) 0.184 ops/ms [Average]
  (min, avg, max) = (17.099, 17.267, 17.511), stdev = 0.122
  CI (99.9%): [17.083, 17.451] (assumes normal distribution)

上面一大堆输出信息，大家直接看重点，在最后 Result "ltd.newbee.mall.MethodNameTest.m1": 这里，平均 ops 是每毫秒 17 次，比较低。

2.使用异常对象的 getStackTrace() 方法

测试代码，

@Benchmark
@BenchmarkMode({Mode.Throughput})
public void m2() {
    // 获取当前方法名
    String methodName = new Throwable().getStackTrace()[0].getMethodName();
}

测试结果，

...
# Run progress: 25.00% complete, ETA 00:04:37
# Fork: 1 of 2
# Warmup Iteration   1: 12.891 ops/ms
# Warmup Iteration   2: 12.873 ops/ms
# Warmup Iteration   3: 13.023 ops/ms
Iteration   1: 25.617 ops/ms
Iteration   2: 25.840 ops/ms
Iteration   3: 25.301 ops/ms
Iteration   4: 24.839 ops/ms
Iteration   5: 25.930 ops/ms

# Run progress: 37.49% complete, ETA 00:03:51
# Fork: 2 of 2
# Warmup Iteration   1: 12.511 ops/ms
# Warmup Iteration   2: 12.329 ops/ms
# Warmup Iteration   3: 13.011 ops/ms
Iteration   1: 23.842 ops/ms
Iteration   2: 24.292 ops/ms
Iteration   3: 25.600 ops/ms
Iteration   4: 25.745 ops/ms
Iteration   5: 25.789 ops/ms


Result "ltd.newbee.mall.MethodNameTest.m2":
  25.280 ±(99.9%) 1.088 ops/ms [Average]
  (min, avg, max) = (23.842, 25.280, 25.930), stdev = 0.720
  CI (99.9%): [24.191, 26.368] (assumes normal distribution)

直接看最后 Result "ltd.newbee.mall.MethodNameTest.m2": 这里，平均 ops 是每毫秒 25 次，也比较低。

3.使用匿名内部类的 getClass().getEnclosingMethod() 方法

测试代码，

@Benchmark
@BenchmarkMode({Mode.Throughput})
public void m1() {
    // 获取当前方法名
    String methodName = Thread.currentThread().getStackTrace()[1].getMethodName();
}

测试结果，

...
# Run progress: 49.99% complete, ETA 00:03:04
# Fork: 1 of 2
# Warmup Iteration   1: 10489.110 ops/ms
# Warmup Iteration   2: 9233.590 ops/ms
# Warmup Iteration   3: 10504.615 ops/ms
Iteration   1: 10695.898 ops/ms
Iteration   2: 10570.155 ops/ms
Iteration   3: 11089.810 ops/ms
Iteration   4: 10805.448 ops/ms
Iteration   5: 10027.222 ops/ms

# Run progress: 62.49% complete, ETA 00:02:18
# Fork: 2 of 2
# Warmup Iteration   1: 11322.008 ops/ms
# Warmup Iteration   2: 10025.593 ops/ms
# Warmup Iteration   3: 10808.095 ops/ms
Iteration   1: 10684.594 ops/ms
Iteration   2: 11241.540 ops/ms
Iteration   3: 10742.348 ops/ms
Iteration   4: 9940.437 ops/ms
Iteration   5: 11226.023 ops/ms


Result "ltd.newbee.mall.MethodNameTest.m3":
  10702.347 ±(99.9%) 672.631 ops/ms [Average]
  (min, avg, max) = (9940.437, 10702.347, 11241.540), stdev = 444.904
  CI (99.9%): [10029.716, 11374.979] (assumes normal distribution)

直接看最后 Result "ltd.newbee.mall.MethodNameTest.m3": 这里，平均 ops 是每毫秒 10702 次。非常夸张，可以看到 ops 对比上面两种方法一下子从几十级别提升到上万级别。

4.Java 9 的 Stack-Walking API

测试代码，

@Benchmark
@BenchmarkMode({Mode.Throughput})
public void m1() {
    // 获取当前方法名
    String methodName = Thread.currentThread().getStackTrace()[1].getMethodName();
}

测试结果，

...
# Run progress: 74.99% complete, ETA 00:01:32
# Fork: 1 of 2
# Warmup Iteration   1: 2191.034 ops/ms
# Warmup Iteration   2: 2141.886 ops/ms
# Warmup Iteration   3: 2192.843 ops/ms
Iteration   1: 2262.279 ops/ms
Iteration   2: 2263.193 ops/ms
Iteration   3: 2201.354 ops/ms
Iteration   4: 2282.906 ops/ms
Iteration   5: 2130.322 ops/ms

# Run progress: 87.48% complete, ETA 00:00:46
# Fork: 2 of 2
# Warmup Iteration   1: 2207.800 ops/ms
# Warmup Iteration   2: 2269.887 ops/ms
# Warmup Iteration   3: 2239.005 ops/ms
Iteration   1: 2001.840 ops/ms
Iteration   2: 2047.698 ops/ms
Iteration   3: 2349.138 ops/ms
Iteration   4: 2362.165 ops/ms
Iteration   5: 2305.982 ops/ms


Result "ltd.newbee.mall.MethodNameTest.m4":
  2220.688 ±(99.9%) 186.910 ops/ms [Average]
  (min, avg, max) = (2001.840, 2220.688, 2362.165), stdev = 123.629
  CI (99.9%): [2033.778, 2407.598] (assumes normal distribution)

直接看最后 Result "ltd.newbee.mall.MethodNameTest.m4": 这里，平均 ops 是每毫秒 2220 次。对比第一种和第二种方案的几十 ops 来说性能提升也很客观，但是对比第三种方法的上万级别 ops 还是不足。

四种方案的最终得分对比

Benchmark           Mode  Cnt      Score     Error   Units
MethodNameTest.m1  thrpt   10     17.267 ±   0.184  ops/ms
MethodNameTest.m2  thrpt   10     25.280 ±   1.088  ops/ms
MethodNameTest.m3  thrpt   10  10702.347 ± 672.631  ops/ms
MethodNameTest.m4  thrpt   10   2220.688 ± 186.910  ops/ms
MethodNameTest.m1     ss   10      0.686 ±   0.289   ms/op
MethodNameTest.m2     ss   10      0.339 ±   0.287   ms/op
MethodNameTest.m3     ss   10      0.031 ±   0.011   ms/op
MethodNameTest.m4     ss   10      0.074 ±   0.027   ms/op

根据最后得分可以看出，四种方案中性能最好的方案是基于匿名内部类的 getClass().getEnclosingMethod() 方案，性能第二是的是基于 Java 9 出现的 Stack-Walking API 方案，其他两种性能过于低下了。