解读堆栈跟踪

Joakim Nordström 于 2021 年 2 月 12 日发布

在本文中，我们将研究当 Java 虚拟机崩溃时生成的崩溃日志，即 hs_err 文件。尝试找出问题所在以及哪个组件出现故障，了解如何解释崩溃日志文件非常重要。重点将放在理解构成堆栈跟踪的帧上。

A hand holding an empty frame in front of a cliff by the sea
照片由 Pine Watt 拍摄

分而崩溃

对于本文，我创建了一个示例，其中包括一个 Java 循环，将一个常量除以一个递减的分母，最终导致除以零。该代码经过一些曲折，以获得更有趣的堆栈跟踪。它包含两个 Java 类：Dumpster 和 Divider；Dumpster 循环，并为每次迭代调用 Divider.do_div()。 Divider 调用本机 JNI 库 libdump.so，该库执行除法。

缩写版本如下所示。可以在我的 GitHub 上找到包含构建和运行说明的完整代码。

Java 类

class Dumpster {
  void main(...) {
    do_loops(no_of_loops);
  }
  
  void do_loops(int no_of_loops) {
    for(int i = no_of_loops; i >= 0; i--) {
        new Divider().do_div(i);
    }
  }
}
class Divider {
  void do_div(int denominator) {
    native_div_call(denominator);
  }
  
  native void native_div_call(int denominator);
}

本机 libdump 库

// This is the native method native_div_call
JNIEXPORT void JNICALL Java_jaokim_dumpster_Dumpster_native_1div_1call 
    (jint denominator) {
  int numerator = 9;
  // call C standard library div
  div(numerator, denominator);
}

运行此程序几个循环将触发崩溃。

duke@cafedead:/work# java Dumpster 10
    #
    # A fatal error has been detected by the Java Runtime Environment:
    #
    #  SIGFPE (0x8) at pc=0x00007fc0b124a5a3, pid=6208, tid=6209
    #
    # JRE version: OpenJDK Runtime Environment (15.0.1+9)
    # Java VM: OpenJDK 64-Bit Server VM (15.0.1+9-18, mixed mode, aot, sharing, tiered, …
->  # Problematic frame:
->  # C  [libc.so.6+0x3a5a3]  div+0x3
    #
    # If you would like to submit a bug report, please visit:
    #   https://bugreport.java.com/bugreport/crash.jsp
->  # The crash happened outside the Java Virtual Machine in native code.
->  # See problematic frame for where to report the bug.

除了有问题的帧之外，还有一些关于发生情况的清晰文本说明：“崩溃发生在 Java 虚拟机外部的本机代码中”和“请参阅有问题的帧以了解在哪里报告错误”。

崩溃发生在 Java 虚拟机外部的本机代码中。

更仔细地研究生成的 hs_err 文件，特别是堆栈跟踪，每个帧的第一个字符告诉我们我们处于哪种代码中。在 hs_err 文件中直接提示了它们的含义

   J=compiled Java code, A=aot compiled Java code, j=interpreted, Vv=VM code, C=native code

我们将从顶部开始遍历堆栈跟踪，从有问题的帧开始，尝试对有用的提示做出更多解释。

    Stack: [0x00007f2b92572000,0x00007f2b92673000],  sp=0x00007f2b92671788,  free space=1021k
    Native frames: (J=compiled Java code, A=aot compiled Java code, j=interpreted, Vv=VM code, C=native code)
->  C  [libc.so.6+0x3a5a3]  div+0x3
    C  [libdump.so+0x1162]  Java_jaokim_dumpster_Divider_native_1div_1call+0x29
    j  jaokim.dumpster.Divider.native_div_call(I)V+0
    j  jaokim.dumpster.Divider.do_div(I)V+2
    j  jaokim.dumpster.Dumpster.do_loops(I)V+14
    j  jaokim.dumpster.Dumpster.doTestcase(Ljava/lang/Integer;)V+5
    j  jaokim.dumpster.Dumpster.main([Ljava/lang/String;)V+58
    v  ~StubRoutines::call_stub
    V  [libjvm.so+0x773a29]  JavaCalls::call_helper(...)+0x299
    V  [libjvm.so+0x804747]  jni_invoke_static(...) [clone .isra.0] [clone .constprop.1]+0x357
    V  [libjvm.so+0x80733f]  jni_CallStaticVoidMethod+0x12f
    C  [libjli.so+0x4627]  JavaMain+0xd17
    C  [libjli.so+0x7fc9]  ThreadJavaMain+0x9

C=本机代码

最上面的帧（即有问题的帧）带有前缀 C。 C 告诉我们这是本机代码。我们看到它在执行函数 div 时在 C 标准库 libc.so 中崩溃。下一个帧也是本机代码，在我们的库 libdump.so 中执行命名奇怪的 Java_jaokim_dumpster_Dumpster_native_1div_1call 函数。

j=解释

在此之前，我们的 Java 类 Divider 和 Dumpster 一直在执行。它们一直在解释模式下执行，小写前缀 j 告诉我们这一点。

Vv=VM 代码

我们的 Java 类和方法在几帧内部原生代码之后被调用；~StubRoutines::call_stub 以小写 v 为前缀，libjvm 帧以大写 V 为前缀。小写表示 VM 生成的代码，大写表示来自内部 libjvm 库的代码（这种区别值得专门说明；理解 v 和 V 是内部 VM 原生代码就足够了）。

我们程序的执行从两个底层帧开始。正如 C 所示，这是来自 libjli Java 启动器库的原生代码。顾名思义，此库启动 JVM，并且是 java 命令用于启动我们的 Java 程序的命令。尽管是 Java 特定的，但它不算是 VM 内部代码，因为它不在 JVM/HotSpot 内存空间中执行。

J=已编译的 Java 代码

让我们来看看大写 J 帧类型，“已编译的 Java 代码”。使用相同的示例，仅将循环次数增加到一千次迭代，我们得到一个稍微不同的堆栈跟踪。

duke@cafedead:/work# java Dumpster 1000
#
# A fatal error has been detected by the Java Runtime Environment:
#

崩溃日志看起来几乎相同，除了 native_div_call 和 do_div_call 的 Java 帧现在有一个大写 J。

    C  [libc.so.6+0x3a5a3]  div+0x3
    C  [libdump.so+0x1162]  Java_jaokim_dumpster_Divider_native_1div_1call+0x29
->  J 56  jaokim.dumpster.Divider.native_div_call(I)V (0 bytes) @ 0x00007f67a87e46db [0x00007f67a87e4620+0x00bb]
->  J 55 c1 jaokim.dumpster.Divider.do_div(I)V (6 bytes) @ 0x00007f67a12b33a4 [0x00007f67a12b3320+0x0084]
    j  jaokim.dumpster.Dumpster.do_loops(I)V+14
    j  jaokim.dumpster.Dumpster.doTestcase(Ljava/lang/Integer;)V+5
    j  jaokim.dumpster.Dumpster.main([Ljava/lang/String;)V+58
    v  ~StubRoutines::call_stub
    V  [libjvm.so+0x773a29]  JavaCalls::call_helper(...)+0x299
    V  [libjvm.so+0x804747]  jni_invoke_static(...) [clone .isra.0] [clone .constprop.1]+0x357
    V  [libjvm.so+0x80733f]  jni_CallStaticVoidMethod+0x12f
    C  [libjli.so+0x4627]  JavaMain+0xd17
    C  [libjli.so+0x7fc9]  ThreadJavaMain+0x9

当我们多次运行循环时，JVM 会将方法 do_div 视为热点，并且不会每次都对其进行解释，而是对其进行即时编译以执行，以便节省宝贵的时钟周期。数字（56 和 55）是编译该方法的任务的 ID，字节数是生成代码的大小，地址指向内存中的已编译代码。

A=aot 编译的 Java 代码

为了全面涵盖不同的帧类型，我们必须使用 JEP 295 的 AOT 功能添加一个预先编译的步骤。此示例显示了我们如何使用 Divider 类的预编译（即预先）版本；使用 jaotc 命令将该类编译到 AOT 库 divider.so 中。我们为 Java 解锁实验模式并添加 AOTLibrary 参数。

duke@cafedead:/work# java -XX:+UnlockExperimentalVMOptions -XX:AOTLibrary="divider.so" Dumpster 1000

查看该崩溃，Divider.do_div() 帧现在以大写 A 为前缀，表明我们正在使用预先编译的方法。

    C  [libc.so.6+0x3a5a3]  div+0x3
    C  [libdump.so+0x1162]  Java_jaokim_dumpster_Divider_native_1div_1call+0x29
    J 55  jaokim.dumpster.Divider.native_div_call(I)V (0 bytes) @ 0x00007fc0987e465b [0x00007fc0987e45a0+0x00bb]
->  A 2  jaokim.dumpster.Divider.do_div(I)V (6 bytes) @ 0x00007fc0afb7d194 [0x00007fc0afb7d120+0x0074]
    j  jaokim.dumpster.Dumpster.do_loops(I)V+14
    j  jaokim.dumpster.Dumpster.doTestcase(Ljava/lang/Integer;)V+5
    j  jaokim.dumpster.Dumpster.main([Ljava/lang/String;)V+58
    v  ~StubRoutines::call_stub
    V  [libjvm.so+0x773a29]  JavaCalls::call_helper(...)+0x299
    V  [libjvm.so+0x804747]  jni_invoke_static(...) [clone .isra.0] [clone .constprop.1]+0x357
    V  [libjvm.so+0x80733f]  jni_CallStaticVoidMethod+0x12f
    C  [libjli.so+0x4627]  JavaMain+0xd17
    C  [libjli.so+0x7fc9]  ThreadJavaMain+0x9

谁导致了崩溃？

在这个特定案例中，我们知道发生了什么；我们进行了零除。即使有问题的帧位于 C 标准库中，并且 hs_err 文件明确告诉我们“查看有问题的帧以了解在哪里报告错误”，但众所周知，C 标准库不太可能如此轻易地崩溃。因此，不要仅仅责怪 libc.so，而应该查看其他帧，看看发生了什么。我们列表中的下一个嫌疑人是我们自己的本机库。是的，可以通过在调用 div 之前检查 denominator 是否为零来在此处修复它。

JNIEXPORT void JNICALL Java_jaokim_dumpster_Dumpster_native_1div_1call 
    (jint denominator) {
  int numerator = 9;
  // call C standard library div
  if(denominator == 0) {
    return;
  }
  div(numerator, denominator);
}

但是，与其实际调用本机代码，不如在 Java 循环中修复它，确保 i 永远不会达到零，方法是将“i >= 0”更改为“i > 0”。

class Dumpster {
  void do_loops(int no_of_loops) {
    for(int i = no_of_loops; i > 0; i--) {
        new Divider().do_div(i);
    }
  }
}

摘要

hs_err 文件对其不同的堆栈帧类型进行了简洁的总结，还提供了有关在哪里报告错误和崩溃的有用提示。

J=compiled Java code, A=aot compiled Java code, j=interpreted, Vv=VM code, C=native code

但是，我们可以将其稍稍增强到下表中，希望这篇文章对其含义提供了进一步的背景。

字符	描述
`j`	由 JVM 在运行时解释的 Java 代码
`J`	由 JVM 即时编译的 Java 代码
`A`	由 `jaotc` 提前编译的 Java 代码
`C`	外部库中的本机代码，不驻留在 JVM 中
`V`	JVM 库部分中的本机代码
`v`	由 JVM 生成的本机代码

进一步阅读

Java 故障排除指南非常适合在排除崩溃的 Java 应用程序故障时需要进一步帮助的情况。本指南提供了有关如何确定崩溃原因的建议，还提供了提示和可能的解决方法。