为 getStackTrace()[2].getMethodName() 获得不同的结果答案

【问题标题】：Getting different results for getStackTrace()[2].getMethodName()为 getStackTrace()[2].getMethodName() 获得不同的结果
【发布时间】：2021-11-23 14:50:35
【问题描述】：

出于日志记录的目的，我创建了一个方法 logTitle()，它会为我们的 TestNG 测试打印出调用方法的名称。示例代码如下。

@Test
public void test1() throws Exception {
    method1();
}

public static void method1() throws Exception {
    Utils.logTitle(2);
}

...

public static void logTitle(Integer level) throws Exception {

    // Gets calling method name
    String method = Thread.currentThread().getStackTrace()[2].getMethodName();
    // This would get current method name
    switch (level) {
    case 1:
        logger.info("=======================================================");
        logger.info(method);
        logger.info("=======================================================");
        break;
    case 2:
        logger.info("------------------------------------");
        logger.info(method);
        logger.info("------------------------------------");
        break;
    case 3:
        logger.info("---------------------");
        logger.info(method);
        logger.info("---------------------");
        break;
    case 4:
        logger.info("--------- " + method + " ------------");
        break;
    default:
        logger.info(method);
    }
}

问题是我在两台不同的机器上得到不同的 logTitle() 结果。

每个人的笔记本电脑都正确返回：

2016-06-20 14:22:06 INFO  - ------------------------------------
2016-06-20 14:22:06 INFO  - method1
2016-06-20 14:22:06 INFO  - ------------------------------------

我们的开发 unix 框返回不同：

2016-06-20 14:42:26 INFO  - ------------------------------------
2016-06-20 14:42:26 INFO  - logTitle
2016-06-20 14:42:26 INFO  - ------------------------------------

这在其他所有人的笔记本电脑上都能正常工作，但在开发 unix 机器上却不行。我认为 dev unix 机器使用的是 IBM 的 Java 版本，而其他人都在使用 Oracle 的 Java 版本，但不确定这是否是罪魁祸首。

有什么想法吗？

【问题讨论】：

可能有一些方法method1的内联？
打印整个堆栈跟踪（不仅仅是第三个元素的方法名称），看看有什么区别？
我怀疑this answer 和它的cmets 会帮助你。
This answer 也可以提供帮助。显然它在不同版本的 Oracle JVM 之间甚至不一致，所以我不希望它在完全不同的 JVM 上是可靠的。

标签： java testng

【解决方案1】：

来自Javadoc：

在某些情况下，某些虚拟机可能会从堆栈跟踪中省略一个或多个堆栈帧。在极端情况下，允许没有关于这个 throwable 的堆栈跟踪信息的虚拟机从这个方法返回一个长度为零的数组。

因此，唯一有保证的方法是使用方面，或使用其他一些自定义方式收集堆栈跟踪。但是您可以将此方法与回退结合起来以某种方式获取当前方法的名称（以防您的 logTitle 方法将被内联）。例如，可以找到here。同样，不能保证，但有更好的机会。

【讨论】：

【解决方案2】：

获得测试方法名称的更简单方法是使用@BeforeMethod 并注入Method。请参阅 TestNG 的文档，here。

只需将名称存储在某处并在您的日志中使用它（为什么不在@AfterMethod 中？）

【讨论】：

我已经在做记录测试方法的名称了，但是在上面，我们谈论的是非测试方法。
我认为您应该更多地解释您的需求：您为什么要这样做？您是否考虑过为此使用方面？
在查看日志文件时帮助排除故障。我们的日志文件非常大，而且我们有很多方法，知道我们最后在哪里，或者什么方法正在打印什么语句，这通常对我们有帮助。抱歉，不熟悉方面，但可以研究一下。
aspect 只是一种在方法之前/之后/周围注入一些代码的方法，并为您提供方法的元数据（如其名称）。但我不知道在测试环境中使用它会有多复杂。另一种解决方案可能是使用 Spock 框架，它提供了您想要的内置功能。但同样，这可能需要太多时间，具体取决于您的工作环境。

【解决方案3】：

我的猜测，正如MeBigFatGuy 所提到的。这可能是因为在进行方法内联优化时，IBM/Oracle JVM 的 JIT 编译器的实现/默认值不同。

我建议在开发 unix 框中运行代码

-Xjit:disableInlining

看看问题是否消失。

如果这对你有用，它可能适合测试，但正如Alexey Adamovskiy 回答中提到的，我们不能相信 java 包含在堆栈帧中。

另见：

【讨论】：

【解决方案4】：

我猜这种行为是特定于 JVM 的。过去我想出了这个解决方案：

// find first stack trace entry that is not in this class
Optional<StackTraceElement> ste = Iterables.tryFind(
        Arrays.asList(new RuntimeException().getStackTrace()), 
        new Predicate<StackTraceElement>() {
            @Override
            public boolean apply(StackTraceElement input) {
                return !input.getClassName().equals(PutYourClassHere.class.getName());
            }
        });

if (ste.isPresent()) {
    LOG.trace("Method called by: {}.{}", ste.get().getClassName(), ste.get().getMethodName());
}

sn-p 使用的是 Google Guava，因为它适用于 Java 7。如果您有 Java 8，则可以使用 Streams API 和 lambdas。我进行了ste.isPresent() 检查，因为我遇到了一次空堆栈跟踪。据我记得，当一次又一次地抛出相同的异常时，Oracle JVM 会跳过堆栈跟踪。

编辑：Java 8 方式

Optional<StackTraceElement> ste = Arrays.stream(new RuntimeException().getStackTrace())
            .filter(x -> !x.getClassName().equals(Utils.class.getName()))
            .findFirst();

【讨论】：

【解决方案5】：

我认为它是导致问题的具体深度，在您的场景中是 2。

所以，不要写

String method = Thread.currentThread().getStackTrace()[2].getMethodName();

如果你写

StackTraceElement[] ste = Thread.currentThread().getStackTrace();
String method = null;
boolean doNext = false;
for (StackTraceElement s : ste) {
       if (doNext) {
          method = s.getMethodName();
          return;
       }
       doNext = s.getMethodName().equals("getStackTrace");
   }

它仅适用于 JDK 1.5+

另一个选项如下：

String method = new Object(){}.getClass().getEnclosingMethod().getName();

或者更慢的选择是：

String method = new Exception().getStackTrace()[0].getMethodName();

因为这每次都会创建一个异常实例。

希望对你有所帮助。

【讨论】：

new Object(){}.getClass().getEnclosingMethod().getName() 比 new Exception().getStackTrace()[0].getMethodName() 快的证据是什么？
@SteffenHarbich 对于第一个选项，它只需要创建一个 Object 实例，而对于第二个选项，它需要创建三个实例：Exception、Throwable 和 Object。为了证明，我编写了一个程序来获取和打印名称 1000000 次，然后我们开始......结果是：1) for new Object(){}.getClass().getEnclosureMethod().getName() 总时间是 7 秒，701 毫秒 476129 纳秒，而对于 2)，对于 new Exception().getStackTrace()[0].getMethodName() 总时间是 12 秒，222 毫秒 112528 纳秒

【解决方案6】：

Log4J finds the method name通过向下搜索堆栈跟踪，直到找到必须传入的目标类名，然后读取方法名。

在您的代码中，您可以使用类似的技术 - 代替静态方法 Utils 您可以在测试中创建一个实例，并传入测试的类：

Utils utils = new Utils(MyTest.class);

然后在Utils.logTitle() 方法中使用前面提到的搜索技术。

Utils.logTitle() 将向前搜索新创建的 Throwable 的堆栈跟踪元素，直到找到具有所需目标类的第一个元素。

【讨论】：

【解决方案7】：

Log4j 2 使用 Logger 的完全限定类名来定位调用 Logger 的类和方法。查找位置的代码如下。随意使用它。

请注意，循环从堆栈跟踪的底部开始；这对于检测递归调用记录器的异常情况是必要的（可能来自已记录对象的toString() 方法）。在这种情况下，我们希望报告调用 Logger 的第一个类/方法，而不是最后一个，因此我们别无选择，只能自下而上遍历堆栈跟踪。

public static StackTraceElement calcLocation(final String fqcnOfLogger) {
    if (fqcnOfLogger == null) {
        return null;
    }
    // LOG4J2-1029 new Throwable().getStackTrace is faster 
    // than Thread.currentThread().getStackTrace().
    final StackTraceElement[] stackTrace = new Throwable().getStackTrace();
    StackTraceElement last = null;
    for (int i = stackTrace.length - 1; i > 0; i--) {
        final String className = stackTrace[i].getClassName();
        if (fqcnOfLogger.equals(className)) {
            return last;
        }
        last = stackTrace[i];
    }
    return null;
}

【讨论】：