之前在写另外一篇文章的时候, 讨论到如果遇到 fatal error, 就能通过 JVM 启动参数 -XX:OnError 来触发执行定制的命令, 以及用 -XX:ErrorFile 来产生 hs_err_pid*.log. 那么什么是 fatal error 呢?

我们知道Java 的错误分为 Error 和 Exception 可是即便抛出一个 Error 并不能触发上面的2个参数, 所以文档里指的 fatal error 肯定是更为严重的错误.

你以前可能看到过 hs_err_pid*.log, 可是真要故意创建一个 fatal error 的时候, 却犯难了.

如何创建一个 fatal error

有趣的是, 但我问 chatGPT 如何创建这种 fatal error 场景的时候, 它提示我: This content may violate our usage policies. 竟然拒绝回答. 当我告诉它, 我只是在做一个本地实验的时候, 它告诉我通过下面3种方法能造成 fatal error:

1. 调用 native C 代码, 读取错误地址的代码, 造成 Segment fault;
2. 错误使用 JVM 参数, 如设置 -XX:CompileThreshold 特小, 导致编译死循环;
3. 手动触发特定 Error, 如 OutOfMemoryError.

试了上面的第三项, 不论是通过消耗内存真造成 OOM 还是直接抛出 OutOfMemoryError 都无法触发.

谷歌搜索了一下, 也没找到我这种想触发的人, 都是遇到这种问题的人.

思路 从JDK 源代码找到可能触发的场景

搜索 hs_err_pid site:openjdk.java.net 可以看到几个相关的issue, 比如 JDK-8220786 和 JDK-8220787 都是讨论把 hs-err 从定向到 stdout 或 stderr 去.

接着继续搜索 github 上的 JDK 源码, 找到下面的代码:
https://github.com/openjdk/jdk/blob/4e5c25ee43d4ec31ed5160fd93a2fd15e35182f8/src/hotspot/share/utilities/vmError.cpp#L1827

fd_log = prepare_log_file(ErrorFile, "hs_err_pid%p.log", true, buffer, sizeof(buffer));

从这里我们看到了如何写入以及什么时候才能写入 hs_err_pid%p.log 的逻辑. 这个代码位于: vmError.cpp 的 VMError::report_and_die 方法, 并且这里面有好几个重载的该方法.

接下来, 我们只要在该 repo 里面搜索什么时候调用这个 report_and_die 方法的, 就能找到我们寻找的触发条件.

其中一处是关于在 linux 平台触发的在 https://github.com/openjdk/jdk/blob/4e5c25ee43d4ec31ed5160fd93a2fd15e35182f8/src/hotspot/os/posix/signals_posix.cpp#L649, 这个方法是: JVM_HANDLE_XXX_SIGNAL, 在其注释中提到 This routine may recognize any of the following kinds of signals: SIGBUS, SIGSEGV, SIGILL, SIGFPE, SIGQUIT, SIGPIPE, SIGXFSZ, SIGUSR1 .

所以, 我们可以使用 linux signal 来测试.

使用 SIGSEGV 测试

在 linux 机器上写一个 main 函数里面让线程 sleep 的代码, 然后启动它. 同时开另外一个窗口, 对它发送 SIGSEGV 信号, 观察到:

$ java -XX:OnError="touch /tmp/eric.txt"  ErrorExample 
$ kill -11 <pid>

发现 /tmp/eric.txt 确实产生了. 同时观察到在当前目录产生了 hs_err_pid702969.log 等日志文件. 虽然Java 进程奔溃会默认产生 core dump, 但是却没有找到 core dump.

为什么没有产生 core dump

JVM 有个启动参数 -XX:+CreateCoredumpOnCrash 默认是打开的, 所以, 理论上当 crash 的时候, 会产生core dump.

$ java -XX:+PrintFlagsFinal -version | grep Core
     bool CreateCoredumpOnCrash                    = true                                      {product} {default}

检查了 ulimit -c 确认是 unlimited, 同时搜索了全磁盘, 没有找到对应的 core dump.
如果查看上面提到的 hs_err_pid702969.log, 就会发现里面这么写的:

# Core dump will be written. Default location: Core dumps may be processed with "/usr/share/apport/apport -p%p -s%s -c%c -d%d -P%P -u%u -g%g -- %E" (or dumping to /home/supra/work/java/error/core.702969)

这里内容提及了 core dump, 以及 apport 和可能放置 core dump 的路径, 但该路径的core dump 却不存在.

apport 是什么

apport 是一款系统程序, 它能拦截应用在 crash 时候的 core dump 数据, 并且生成详细的report. 对于绝大多数用户来说, 遇到程序crash生成 core dump 并不能带来什么价值, 如果把 core dump 转成一份可以被用户或者admin 能读取的固定格式报告, 将会非常有用, apport 就是这么一种程序, 官方网站: https://wiki.ubuntu.com/Apport

如果你使用桌面版本的 Ubuntu 发行版, 在程序crash 的时候, 你可能会看到一个弹窗, 问你要不要发送crash report 给 ubuntu 官方, 它就是 apport 的结果.

通常它产生的 crash report 在 /var/crash/ 文件夹.

为什么 core dump 被 apport 接管了?

查看 core dump 的官方文档: https://man7.org/linux/man-pages/man5/core.5.html.
可以看到: /proc/sys/kernel/core_pattern 是一个内核参数，用于控制核心转储文件的生成方式。当一个进程崩溃时，内核会查看 core_pattern 的值来决定如何处理核心转储。

core_pattern 可以包含以下几种类型的值：

1. 静态文件路径：如果 core_pattern 包含一个普通的文件路径（不包含管道符 |），核心转储文件将被写入该路径指定的位置。路径中可以包含一些特殊的格式化字符（如 %p 表示进程 ID），这些字符会被替换为相应的值，以便为每个核心转储生成唯一的文件名。
2. 管道命令：如果 core_pattern 的值以管道符 | 开头，后面跟随的是一个命令，那么内核会执行该命令，并将核心转储数据作为标准输入传递给它。这允许将核心转储数据发送到一个自定义的处理程序，如 Apport 或 Systemd-coredump，而不是直接写入文件系统。

如: /var/coredumps/core.%e.%p 或 |/usr/share/apport/apport %p %s %c %d %P %u %g -- %E

我实验用的 linux 版本就是上面的带管道的例子, 所以, 它使用 apport 生成了 crash dump, 我去 /var/crash/ 目录, 就看到了 crash report _usr_lib_jvm_java-11-openjdk-amd64_bin_java.1000.crash.

现在如何产生 core dump

1. 使用 -XX:OnError="gdb %p"
2. 修改 /proc/sys/kernel/core_pattern 为 core dump 文件模版(去除管道).

$ java -XX:OnError="gcore %p"  ErrorExample
$ ls -alh | grep core
$ core.720444

总结

1. -XX:OnError 决定当致命错误是干啥
2. -XX:ErrorFile 决定了 hs_err 日志的文件名, 还有另外两个类似的参数决定是不是写到 stdout 和 stderr.
3. -XX:+CreateCoredumpOnCrash 决定了崩溃时默认产生core dump, core dump 文件名或怎么处理根据 /proc/sys/kernel/core_pattern 来定.

JDPA 是一个框架, 它定义了 debugger 和 debuggee 是如何交互的, 两端交互的API 和 协议, 并不包含具体的实现. 它包含3部分.

1. debugger 端的API: JDI (Java Debug Interface)
2. debuggee 端的API: JVM TI
3. 连接两端的协议: JDWP

jdb

jdb 是 JDK 自带的命令行 debugger 端, 是 JDI 的实现.

1. 它能连接本地和远程的目标 Java 应用, 执行 debug 命令.
2. 它能连接本地和远程的 core dump 文件, 并获取信息.

3. 它能启动本地要debug 的Java 应用, 并且debug.

   jdb -connect sun.jvm.hotspot.jdi.SAPIDAttachingConnector:pid=9302
   jdb -connect com.sun.jdi.SocketAttach:port=12306
   jdb -connect sun.jvm.hotspot.jdi.SACoreAttachingConnector:javaExecutable=$JAVA_HOME/bin/java,core=core.20441
   远程的 core dump 需要 jsadebugd. 

jdb 本地启动一个app 的背后

下面本地启动一个需要debug的app, 然后观察 jdb 是如何跟这个app交互的.

$ jdb FreeMemoryExample # 启动 jdb 
$ stop at FreeMemoryExample:8 # 设置断点
$ run # 启动应用. 

打开另外一个窗口, 然后观察如下:

$ jps #查看当前机器的 java 进程
3790574 TTY
3790626 FreeMemoryExample
3793734 Jps #jps 本身

$ sudo lsof -T -p  3790574 | grep 5598 #查看进程 3790574 里面连接的 tcp, 它的55985连到本地 55888
jdb     3790574 supra    6u  IPv6           37707266       0t0      TCP suprabox:55985->localhost:55888
$ sudo lsof -T -p 3790626 | grep 5598 #查看进程 3790626 里面连接的 tcp, 它的55888连到本地 55985
java    3790626 supra    4u  IPv4           37703541       0t0      TCP localhost:55888->suprabox:55985
$ ps aux | grep 3790626 #查看 3790626 的启动命令
supra    3790626  0.1  0.2 7021672 41712 pts/0   Sl+  00:06   0:01 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -Xdebug -Xrunjdwp:transport=dt_socket,address=suprabox:55985,suspend=y FreeMemoryExample
$ ps aux | grep 3790574 #查看 3790574 的启动命令
supra    3790574  0.2  0.4 7619496 65040 pts/0   Sl+  00:06   0:02 jdb FreeMemoryExample

所以, 当运行 jdb FreeMemoryExample 的时候, 其实它调用java 进程另外启动了需要被 debug 的程序,并且建立了 tcp socket 通信.

被启动的进程使用了参数: -Xdebug -Xrunjdwp:transport=dt_socket,address=suprabox:55985,suspend=y

添加 debug 参数启动应用, 并连接

只要在对应的 Java 进程启动的时候, 添加类似如下参数, 就能启动debug 监听端口, 等待准备被连接:

$ java -agentlib:jdwp=transport=dt_socket,server=y,address=12306 FreeMemoryExample #启动应用端
# 更多参数参看: https://docs.oracle.com/javase/8/docs/technotes/guides/jpda/conninv.html

$ jdb -connect com.sun.jdi.SocketAttach:port=12306 # 启动jdb 并连接
 stop at FreeMemoryExample:8  # 设置断点
 run # 开始运行
 locals #显示本地变量
 where # 显示栈

写了很多年Java 程序, 很少有机会去使用 JDB debug Java 程序. 因为本地都是使用 IDE 里面的工具, 对于没有桌面的生产环境, 基本都是加入打日志的新代码, 或者使用 Btrace/Bytesman 进行注入. 今天我们将使用 Jdb 在生产环境debug 一段代码.

debug 一段简单的代码

下面是使用 MBean 获取系统剩余空闲内存的代码, 我们将用 jdb 去debug 它.

import java.lang.management.ManagementFactory;
import com.sun.management.OperatingSystemMXBean;

public class FreeMemoryExample {
    @SuppressWarnings("restriction")
    public static void main(String[] args) {
        OperatingSystemMXBean osBean = (OperatingSystemMXBean) ManagementFactory.getOperatingSystemMXBean();
        long freePhysicalMemorySize = osBean.getFreePhysicalMemorySize();
        System.out.println("Free Physical Memory Size: " + freePhysicalMemorySize + " bytes");
    }
}

下面编译这段代码并且进入 debug 运行:

$ javac FreeMemoryExample.java
$ jdb FreeMemoryExample
nitializing jdb ...
> stop at FreeMemoryExample:8
Deferring breakpoint FreeMemoryExample:8.
It will be set after the class is loaded.
> run
run FreeMemoryExample
Set uncaught java.lang.Throwable
Set deferred uncaught java.lang.Throwable
>
VM Started: Set deferred breakpoint FreeMemoryExample:8

Breakpoint hit: "thread=main", FreeMemoryExample.main(), line=8 bci=7
8            long freePhysicalMemorySize = osBean.getFreePhysicalMemorySize();

上面的运行过程中, 我们把断点设置在 FreeMemoryExample 的第八行. 然后执行 run 命令, 启动程序, 然后程序停在了第8行, 并且打印了该行代码.

执行 list 子命令, 显示当前行的前后几行代码.

main[1] list
4    public class FreeMemoryExample {
5        @SuppressWarnings("restriction")
6        public static void main(String[] args) {
7            OperatingSystemMXBean osBean = (OperatingSystemMXBean) ManagementFactory.getOperatingSystemMXBean();
8 =>         long freePhysicalMemorySize = osBean.getFreePhysicalMemorySize();
9            System.out.println("Free Physical Memory Size: " + freePhysicalMemorySize + " bytes");
10        }
11    }

执行 threads 子命令, 显示所有线程

main[1] threads
Group system:
  (java.lang.ref.Reference$ReferenceHandler)0x16c Reference Handler running
  (java.lang.ref.Finalizer$FinalizerThread)0x16d  Finalizer         cond. waiting
  (java.lang.Thread)0x16e                         Signal Dispatcher running
Group main:
  (java.lang.Thread)0x1                           main              running (at breakpoint)
Group InnocuousThreadGroup:
  (jdk.internal.misc.InnocuousThread)0x198        Common-Cleaner    cond. waiting

执行 locals 子命令, 显示所有本地变量

main[1] locals
Local variable information not available.  Compile with -g to generate variable information

可以看到这次并没有显示本地变量, 是因为在编译的时候没有加 -g 参数. javac 关于 -g 参数的说明如下:

  -g                           Generate all debugging info
  -g:{lines,vars,source}       Generate only some debugging info
  -g:none                      Generate no debugging info

所以 -g 就是添加 debugging 信息的. 所以, 我们重新编译一下, 然后继续上面的 locals 子命令

main[1] locals
Method arguments:
args = instance of java.lang.String[0] (id=831)
Local variables:
osBean = instance of com.sun.management.internal.OperatingSystemImpl(id=832)

这次我们可以看到 main 函数的参数 args 和 osBean 变量.

添加方法进入断点

我们可以看到下面讲要执行 OperatingSystemImpl.getFreePhysicalMemorySize, 我们进入这个方法的段点, 并通过执行 cont 执行到该断点.

main[1] stop in com.sun.management.internal.OperatingSystemImpl.getFreePhysicalMemorySize
Set breakpoint com.sun.management.internal.OperatingSystemImpl.getFreePhysicalMemorySize
main[1] cont
>
Breakpoint hit: "thread=main", com.sun.management.internal.OperatingSystemImpl.getFreePhysicalMemorySize(), line=243 bci=0

执行 where 查看当前的栈

main[1] where
  [1] com.sun.management.internal.OperatingSystemImpl.getFreePhysicalMemorySize (OperatingSystemImpl.java:243)
  [2] FreeMemoryExample.main (FreeMemoryExample.java:8)

通过 help 子命令, 我们可以看到所有的子命令.

如何通过 jdb 连接一个正在运行的程序

上面的例子都是通过 jdb 启动想要调试的程序, 那么如何调试另一个独立的程序呢? 我们先看一下 IDE 是如何做的, 首先, 我们本地使用 Eclipse 打开刚才的程序, 设置断点, 然后启动程序. 这个时候, 应用停在断点处. 我们查看这个应用是如何启动的.

$ jps
57184 FreeMemoryExample
69238 Eclipse
57225 Jps
$ jcmd 57184 VM.command_line
57184:
VM Arguments:
jvm_args: -agentlib:jdwp=transport=dt_socket,suspend=y,address=localhost:63529 -javaagent:/Users/xiatian/work/tools/eclipse/Eclipse.app/Contents/Eclipse/configuration/org.eclipse.osgi/223/0/.cp/lib/javaagent-shaded.jar -Dfile.encoding=UTF-8
java_command: FreeMemoryExample

可以看到 Eclipse 启动程序的时候, 添加了 -agentlib:jdwp=transport=dt_socket,suspend=y,address=localhost:63529 这就是启动调试的关键. 它相当于在应用端开启了一个端口在 63529 监听端口并可以完成某些命令, 然后 jdb 通过连接找个端口, 使用 jdwp 协议与之通信, 完成 jdb 的各种命令.

连接器 是Java调试器（JDB）与被调试的Java程序之间通信的接口。它允许JDB与正在运行的Java程序建立连接，并在程序执行时进行交互式的调试操作。

jdb 的 connectors 子命令能显示当前 jdb 支持的连接器, 如:

Connector: com.sun.jdi.ProcessAttach  Transport: local
Connector: com.sun.jdi.RawCommandLineLaunch  Transport: dt_socket
Connector: com.sun.jdi.SocketAttach  Transport: dt_socket

ref:

• 关于 JPDA 的 https://docs.oracle.com/javase/8/docs/technotes/guides/jpda/conninv.html
• 关于 JVM 启动调试参数: https://docs.oracle.com/javase/8/docs/technotes/guides/jpda/conninv.html

最近有个同事找我来看一个Java 应用的内存问题: 他的一个Java应用运行在一个8G内存的机器上, 配置的 Java heap 最大值是2G, 然而这个应用还有个页面能看到系统剩余空闲内存, 上面显示只有500M多的剩余. 他们想给这个应用加大 heap, 却看到只有500M剩余, 不敢加了.

初步看了下机器的内存, 确实是 free 内存是500多M, 然而那是绝对剩余的内存, 没有去掉随时可以回收的 buffer/cache 占用的内存. 如果去掉 buffer/cache 可以释放的内存, 剩余有近5G.

类似如下图:

那么它看到的500M是哪里来的呢? 经过他们翻找源代码, 发现来自于 MBean:

OperatingSystemMXBean.getFreePhysicalMemorySize()

这个 OperatingSystemMXBean 是根据操作系统不同有不同的实现, 但是根据这个测试类 GetFreePhysicalMemorySize 我们可以发现, 它其实取之于: cat /proc/meminfo 的 MemFree, 由此推断, 它就是 free -m 里面的 free 列, 并不是 available 还可以通过释放 buffer/cache 去释放很多.

buffer/cache 就是操作系统为了最大化内存的使用价值而做的: buffer - 其实需要直接写到磁盘, 但是现在直接扔到内存, 等需要的时候, 再写到磁盘. cache - 不用直接从磁盘去取了, 而是把常用的放在内存随时快速使用.

找出源代码

写一段使用 OperatingSystemMXBean 获取空闲内存的代码:

import java.lang.management.ManagementFactory;
import com.sun.management.OperatingSystemMXBean;

public class FreeMemoryExample {
    @SuppressWarnings("restriction")
    public static void main(String[] args) {
        OperatingSystemMXBean osBean = (OperatingSystemMXBean) ManagementFactory.getOperatingSystemMXBean();
        long freePhysicalMemorySize = osBean.getFreePhysicalMemorySize();
        System.out.println("Free Physical Memory Size: " + freePhysicalMemorySize + " bytes");
    }
}

编译并用 jdb 执行:

$ javac -g FreeMemoryExample.java

$ jdb FreeMemoryExample
Initializing jdb ...
> stop at FreeMemoryExample:8
Deferring breakpoint FreeMemoryExample:8.
It will be set after the class is loaded.
> run
run FreeMemoryExample
Set uncaught java.lang.Throwable
Set deferred uncaught java.lang.Throwable
>
VM Started: Set deferred breakpoint FreeMemoryExample:8

Breakpoint hit: "thread=main", FreeMemoryExample.main(), line=8 bci=7
8            long freePhysicalMemorySize = osBean.getFreePhysicalMemorySize();

main[1] locals
Method arguments:
args = instance of java.lang.String[0] (id=831)
Local variables:
osBean = instance of com.sun.management.internal.OperatingSystemImpl(id=832)

main[1] methods com.sun.management.internal.OperatingSystemImpl
** methods list **
com.sun.management.internal.OperatingSystemImpl <init>(sun.management.VMManagement)
com.sun.management.internal.OperatingSystemImpl getCommittedVirtualMemorySize()
com.sun.management.internal.OperatingSystemImpl getFreePhysicalMemorySize()
com.sun.management.internal.OperatingSystemImpl getTotalPhysicalMemorySize()
com.sun.management.internal.OperatingSystemImpl getCommittedVirtualMemorySize0()
com.sun.management.internal.OperatingSystemImpl getFreePhysicalMemorySize0()
com.sun.management.internal.OperatingSystemImpl getFreeSwapSpaceSize0()
...

可以看到 osBean 的类是: com.sun.management.internal.OperatingSystemImpl. 查找 JDK 可以看到有 windows 和 unix 版本. 其中 unix 版本核心的代码是:

#else // solaris / linux
    jlong num_avail_physical_pages = sysconf(_SC_AVPHYS_PAGES);
    return (num_avail_physical_pages * page_size);

AI 对这2行代码的解释:

这段C代码用于获取系统中可用的物理页面数，并计算可用物理内存的总大小。

1. jlong num_avail_physical_pages = sysconf(_SC_AVPHYS_PAGES);：

   1. sysconf() 是一个用于获取系统配置信息的函数，位于 <unistd.h> 头文件中。
   2. _SC_AVPHYS_PAGES 是一个参数，用于指示我们要获取系统中可用的物理页面数。这个参数是一个宏定义，表示系统中可用的物理内存页面的数量。
   3. sysconf(_SC_AVPHYS_PAGES) 调用返回的值将被赋给 num_avail_physical_pages 变量，该变量的类型为 jlong，通常在Java Native Interface (JNI) 中用于表示Java中的 long 类型。

2. return (num_avail_physical_pages * page_size);：

   1. page_size 变量应该是一个代表页面大小的值。在大多数情况下，页面大小是一个固定的值，通常在操作系统的头文件中定义。例如，在Linux系统中，PAGE_SIZE 宏定义了页面的大小。
   2. num_avail_physical_pages * page_size 计算了可用物理内存的总大小，即可用的物理页面数乘以页面大小。
   3. 最后，这个总大小被作为函数的返回值返回。

   综上所述，这段代码的主要作用是通过查询系统配置信息获取可用的物理页面数，然后计算可用物理内存的总大小，并将其作为函数的返回值返回。

所以,可以看到这里只是查看绝对空闲内存的数量, 然后再乘以每个页面大小.

我们分析 Java heap dump 的时候, 经常发现里面包含很多 java.lang.String, 可是让我们回想到底哪里用了这么多 String 的时候, 确实很难列举. 如此多的 String 肯定占用了很多宝贵的内存空间, 那么有什么办法能减少 String 的空间占用呢?

下面一个 heap dump 的 object histogram 的截图, 可以看到 String 的数量仅次于 byte[], 位居第二.

如果你去研究为啥这么多 byte[], 最终你会发现, 其实是 String 太多, 每个 String 对象的背后也是一个byte[].

String 也是 immutable 的对象, 也就是说你对 String 的任何修改会直接创建另外一个新的对象.

另外, 我们会发现, 其实我们的内存里面有很多重复的 String. 通过 MAT 的 “Java Basics” -> "Group by value", 我们对 java.lang.String 进行分组, 可以看到很多重复的字符串.

如下图, 在一个只有 158 MB的 heap 里面, https 这个 String 竟然有 70397 个实例对象.

如果我们添加 -XX:+UseStringDeduplication, 经过一段时间的稳定运行后, 我们可以看到, 虽然 String 还是那么多, 但是 byte[] 已经大幅减少:

对比上图我们发现:

1. String 数量还是差不多, 但是 byte[] 明显减少.
2. String 对象 retained size 明显减少, 就是因为它们引用的 bytes[] 很多都合并了.

我们以 https 这个字符串为例, 可以看到他们引用的 byte[] 都是一个:

对比 intern()

使用 intern()方法, 返回的字符串常量都是字符串常量池里面的同一个.
使用 UseStringDeduplication, 一开始是在EDEN 区域分配的时候, 每个String 都是新的, byte[] 也是不一样的, 当被GC 回收次数达到 StringDeduplicationAgeThreshold 的时候, 会有后台线程处理, 把 bytes[] 指向常量池里的那个字符串. 但是 String 对象本身还是之前的.

uint StringDeduplicationAgeThreshold          = 3                                         {product} {default}
bool UseStringDeduplication                   = false                                     {product} {default}
bool PrintStringTableStatistics               = false                                     {product} {default}

为什么 UseStringDeduplication 默认是关闭的

1. String 的 byte[] 一开始还少正常每个都分配空间的, 等被回收次数到达 StringDeduplicationAgeThreshold 后, 才会有后台线程更改 byte[], 所以需要在 GC 后额外占用时间.
2. 更改这些指针还需要额外CPU.
3. 需要额外内存记录被回收次数.