Java 无法 attach 到目标进程, 使用 core dump 转换为 Java heap dump

有时候, 当我们尝试对一个已经 GC overhead 非常高的 Java 应用进程去做 heap dump 的时候, 或者使用 jstack/jcmd 去做 thread dump 的时候, 发现我们跟本没办法 attach 到目标 Java 进程, 得到下面的错误:

/usr/bin/jcmd 7674 GC.heap_dump /tmp/heap.log.hprof
7674:
com.sun.tools.attach.AttachNotSupportedException: Unable to open socket file: target process not responding or HotSpot VM not loaded
at sun.tools.attach.LinuxVirtualMachine.<init>(LinuxVirtualMachine.java:106)
at sun.tools.attach.LinuxAttachProvider.attachVirtualMachine(LinuxAttachProvider.java:63)
at com.sun.tools.attach.VirtualMachine.attach(VirtualMachine.java:213)
at sun.tools.jcmd.JCmd.executeCommandForPid(JCmd.java:140)
at sun.tools.jcmd.JCmd.main(JCmd.java:129)

一般我们会多尝试几次, 期望有哪次可以 attach 到目标 Java 进程, 不过有时候, 尝试好多次都无法达到目的.

除了这种尝试的方法之外, 我们还可以尝试另外一种方式: 先获得目标进程的 core dump, 再从 core dump 转成 Java heap dump.

具体的方法步骤是:

  1. 安装 gcore

    $ sudo apt install gdb -y   #gcore command in gdb package
  2. 设置 core dump 可允许的大小. 通常生产环境的 core dump 都是禁止的, 一方面 core dump 特别大, 占用磁盘比较大, 另外 core dump 可能包含运行时内存的敏感数据. 如果你的生产环境的 core size 是 unlimited 的或者特别大, 可以忽略这步.

    $ sudo cp /etc/security/limits.conf /etc/security/limits.d/   # 复制limits.conf模板文件到配置文件夹
    $ sudo vim /etc/security/limits.d/limits.conf     # 编辑配置文件, 修改我们目标 Java 进程的用户的配置
    #### 我们假设我们的目标进程使用 appUser 运行, 给他设置 core file 的 hard, soft 允许大小
             appUser hard core unlimited
             appUser soft core unlimited
    
    $ sudo su appUser  # 切换到 appUser
    $ ulimit -a        # 查看它的 core file size 的 hard, soft 大小   
    ### 有时候, 即便你改好了, 还是看到 core size 是0, 不过不要悲观, 继续下去, 可以参数 core dump.                                                                         
    $ exit             # 退出 appUser 
  3. 获取 core dump

    $ pgrep java   # 显示查看目标进程的 pid
    $ sudo gcore <pid>     # 使用 gcore 获取 core dump, 根据目标进程的内存占用大小, 可能会花费不同的时间
    ### 有时候使用别的用户, 即使使用 sudo 也不能 ptrace, 会得到 ptrace 无法 attach 的错误, 这时候, 切换到
    ### appUser 用户, 直接 gcore <pid> 就行. 如果报无法写入, 看你在哪个文件夹, 到一个可写的文件夹就好了
    $ ls -lah core.<pid>   # 查看获取的 core dump 的大小, 通常在当前目录
  4. 把 core file 的 hard, soft 修改的配置改回来

    $ sudo rm -f /etc/security/limits.d/limits.conf # 之前我们把模板加到这个文件, 现在删掉
  5. 转换 core dump 到 Java heap dump. 一定要使用运行对应目标进程运行的 JDK.
    如果你是 Hotspot JDK (Oracle 或者 OpenJDK):

    $ find /app -name jmap     # 找到运行目标进程的 JDK 里面的 jmap 命令
    $ sudo /usr/bin/jmap  -dump:format=b,file=heap.hprof  /usr/bin/java ./core.<pid>   #转换

    如果你是 IBM J9 JDK:

    $ find /app -name jextract  # 找到运行目标进程的 JDK 里面的 jextract 命令
    $ jextract core.<pid>       # 从 core dump 转成 heap dump core.<pid>.zip
    ## 对于这个 core.<pid>.zip 使用 MAT 并且安装的 dtfj 插件, 可以打开, 或者使用 IBM JDK 的 jdmpview 工具里 
    ## 面的 heapdump 命令, 可以把 这个 zip 文件转换成 IBM PHD 格式的 heap dump, 然后使用带 DTFJ 插件的 MAT 
    ## 工具分析. 
    $ /usr/bin/jdmpview 
    $ heapdump
    $ ls -lah
    -rw-r--r--  1 root    root    7.5G Aug 21 17:51 core.16751
    -rw-rw-r--  1 user1   user1   926M Aug 21 19:09 core.16751.zip
    -rw-rw-r--  1 user1   user1    19M Aug 21 19:46 core.16751.zip.phd

    到这里, 获取 heap dump 的过程结束, 下面是怎么从 prod 环境复制 heap dump 到本地环境. 你可以选择使用 scp 或者 rsync 复制到本地, 也可以向下面一样, 使用 nc 建立一个下载服务器, 从本地下载.

  6. 设置 nc 下载服务

    $ sudo apt install netcat -y # 若 nc 没有安装, 则安装
    $ sudo nc -4 -v -l 7070 < ./heap.hprof   # 一种 nc 支持这种参数
    $ sudo nc -v -l -p 7070 < ./heap.hprof   # 另外一种支持这种参数
  7. 下载到本地

    1. 使用浏览器访问 http://<;host>:7070/
    2. 或者使用 curl 命令去下载 → curl "http://<host>:7070/" --output heap.hprof
  8. 清理

    $ rm core.<pid>  dump.hprof

    有了 Heap dump, 你就可以使用 MAT 或者 JVisualVM 查看里面的内容了.

wireshark TSL 1.0 显示协议列为 1.2 的问题

今天遇到一个问题: 新代码发布上去之后, 应用程序启动失败, 显示如下报错信息:

ConnectionException: Socket connection to security.tianxiaohui.com:443 failed with 1 retries
Received fatal alert: protocol_version

从这个出错信息看, 这个客户端连接对应的 server 的 https 出错, 出错的信息显示协议版本问题. 遇到这种问题, 一般我们都会认为客户端和服务端的 TLS 协议的版本不一致造成的.
为了尽快恢复问题, 我们立即对新版本 rollback. 可是出乎意料的是, 老版本也报这个错. 只能这么猜测: 这个 https 访问只在服务器启动的时候访问, 上次老版本发布的时候, 两端的 TLS 协议版本还是能够匹配工作的. 从上次发布完到最近一次新版本发布, 服务器端做了改动, 导致应用不管老版本, 还是新版本, 都无法访问这个 https 的服务.

为了确认这个猜想, 我们对服务器重启, 以便获取 tcp dump, 然后去验证. 结果在使用 wireshark 对这个 tcpdump 进行分析的时候, 遇到了这个 wireshark 显示 TLS 版本不统一的问题, 如下图:
tls.png

在 Protocol 列, 无论是 client hello 还是 server 的 response 都显示为 TLSv1.2, 其实如果查看 client 的详细版本, 会发现内部其实是 TLSv1.0. 如果不仔细查看, 可能会得出错误的结论.

为什么会出现这种情况呢? 这要回到 wireshark 的 SSL dissector 的源码, 从源码看, 对于这个 client hello 协议版本的判断, 是即根据 client 又根据 server 两边做判断的. 正常情况下, 2 端都是一直的, 或能正常协商的情况下, 依照服务端版本取值的. 如果服务端没回应, 这个时候, 是以 client 端的 client hello 的版本做设置的. 我们这里出现的这个问题, 就是属于服务端有回应, 是不同的版本, 导致 wireshark 的显示为和 client 真正发的不一致的问题.

官方网站有个这样的问题: https://www.wireshark.org/lists/wireshark-users/201701/msg00004.html

Browsing the SSL dissector's code it appears that the SSL session
version is based on not just the client hello but also the server

  1. So it would seem that in file-c.pcap the server has responded
  2. TLS v1.2 is used while in file-u.pcap either the server's

response was not seen or responded that TLS 1.0 will be used.

诊断一台服务器 CPU 稍微偏高的问题案例

运行同一Java web 应用的一个集群里面, 有台服务器最近 CPU 的使用率持续偏高一些, 其它服务器的 CPU 使用率大概都在5%一下, 而这台服务器却保持在15%左右. 它运行的代码和其它server 的代码一模一样. 另外即便重启应用, 还是一样的问题.
cpualittlehigh.png

那么这台服务器为什么会出现这种问题呢? 首先做了 profiling, 发现它的火焰图和其它服务器的火焰图并无二致. 如果登上机器, 使用 top 命令查看, 明显看到它的 CPU 使用率要相对高一些. 另外, 我们发现这台服务器上的所有的进程的 CPU 使用率相对其它同样服务器高一些.

使用 vmstat 命令, 我们可以看到, 它的 interrupt 和 context switch 明显比其他服务器高:
inter&cs.png

于是进一步查看 /proc/interrupts, 也能明显确认 Rescheduling Interrupts 也明显高(这个是累计, 可以使用 procinfo 查看 per second):
res.png

一般来说, 这种 Interrupts 都是由于某个进程持续不断的发出中断导致的, 这种发出中断的进程要想一只发生中断, 那么它也也要不断的运行, 它的 CPU 使用率也不会太低. 所以经常见的就是排除法 -> shutdown 某个进程, 看系统 CPU 使用率有没有改进. 于是我们尝试了对 CPU 使用率较高的几个进程使用了排除法. 可以仍然没有奏效.

考虑到这个 server 是一个 VM (使用 KVM), 所以我们有进一步查看了同一个 Hypervisor 上面的其它 VM, 发现其它 VM 也有相同的问题, 于是我们转而怀疑问题出现在 Hypervisor 上面.

于是对 Hypervisor 上的进程使用排除法, 实际排除的时候先找最像的. 于是我们找到了这个元凶进程 -> kswapd0:
image2020-8-18_2-4-41.png

从上面截图可以看到这个 kswapd 进程 CPU 使用率并不低, swap 的使用量(used)的是3.9G, 其实最开始发现它的时候是 swap 14个G, 后来截图的时候, 已经通过 swapoff 释放了很多.

关于 cgroup

cgroup 有现在(2020)有 2 个版本, 尽管大部分公司还在使用 v1, 不过 v2 更好. 官方文档:
https://www.kernel.org/doc/Documentation/cgroup-v1/
https://www.kernel.org/doc/Documentation/cgroup-v2.txt

下面的内容都是基于 v1:

如何查看一个进程的 cgroup 的 group name?

$ pgrep java #找到我要查看的进程号
23850
# cat /proc/23850/cgroup #这个进程的 cgroup 名字
11:devices:/docker/dfa566d
10:pids:/docker/dfa566d
9:blkio:/docker/dfa566d
8:hugetlb:/docker/dfa566d
7:freezer:/docker/dfa566d
6:cpuset:/docker/dfa566d
5:memory:/docker/dfa566d
4:cpuacct,cpu:/docker/dfa566d
3:net_prio,net_cls:/docker/dfa566d
2:perf_event:/docker/dfa566d
1:name=systemd:/docker/dfa566d

$ mount | grep cgroup # 查看 cgroup 文件系统挂载的路径 默认是 /sys/fs/cgroup/
tmpfs on /sys/fs/cgroup type tmpfs (ro,nosuid,nodev,noexec,mode=755)
(rw,nosuid,nodev,noexec,relatime,net_prio,net_cls)
cgroup on /sys/fs/cgroup/cpu,cpuacct type cgroup (rw,nosuid,nodev,noexec,relatime,cpuacct,cpu)
cgroup on /sys/fs/cgroup/memory type cgroup (rw,nosuid,nodev,noexec,relatime,memory)
cgroup on /sys/fs/cgroup/cpuset type cgroup (rw,nosuid,nodev,noexec,relatime,cpuset)
...
cgroup on /sys/fs/cgroup/pids type cgroup (rw,nosuid,nodev,noexec,relatime,pids)
cgroup on /sys/fs/cgroup/devices type cgroup (rw,nosuid,nodev,noexec,relatime,devices)

$ ls -lah /sys/fs/cgroup/cpu/docker/dfa566d/  #该进程的 cgroup 文件
-rw-r--r-- 1 root root 0 Aug 13 05:05 cgroup.clone_children
--w--w--w- 1 root root 0 Aug 13 05:05 cgroup.event_control
-rw-r--r-- 1 root root 0 Aug 13 05:07 cgroup.procs
-r--r--r-- 1 root root 0 Aug 13 05:05 cpuacct.stat
-rw-r--r-- 1 root root 0 Aug 13 05:05 cpuacct.usage
-r--r--r-- 1 root root 0 Aug 13 05:05 cpuacct.usage_percpu
-rw-r--r-- 1 root root 0 Aug 13 05:05 cpu.cfs_period_us
-rw-r--r-- 1 root root 0 Aug 13 05:05 cpu.cfs_quota_us
-rw-r--r-- 1 root root 0 Aug 13 05:05 cpu.rt_period_us
-rw-r--r-- 1 root root 0 Aug 13 05:05 cpu.rt_runtime_us
-rw-r--r-- 1 root root 0 Aug 13 05:05 cpu.shares
-r--r--r-- 1 root root 0 Aug 13 05:05 cpu.stat
-rw-r--r-- 1 root root 0 Aug 13 05:05 notify_on_release
-rw-r--r-- 1 root root 0 Aug 13 05:05 tasks

CPU:

https://www.kernel.org/doc/Documentation/scheduler/sched-bwc.txt
https://engineering.squarespace.com/blog/2017/understanding-linux-container-scheduling
cpu usage soft限制: 使用 cpu.shares 文件. 它基于各 group 之间的比重, 默认比重是 1024. 如果某个 group 的进程使用量达不到自己的比重, 就会把自己剩余的 CPU 使用时间放到一个公共的 pool, 其它使用量超过自己使用量的比重的 group 里面的进程都可以到这个 pool 去取用. 当公共 pool 里面没有可用的时候, 就按照竞争CPU 的各个 group 的比重去分配. 所以如果竞争不激烈, 这个值意义不大, 比重低的group 里面的进程也有可能使用最多的 CPU(其他 group 都有剩余).

cpu usage hard 限制: 使用 cpu.cfs_period_us & cpu.cfs_quota_us 配合. period 代表一段时间, 单位是微妙,默认值是 100ms (100000), 最大值是 1s (1000000). quota 代表在 period 期间该 group 可以使用的量, 最小可能值是 1ms(1000). -1 代表不限制. 在多 CPU core 情况下, quota 的值可能比 period 大, 代表可能是用 n 个 CPU, 比如 period 是 100ms, quota 是 300ms 代表可以使用 3 个 CPU 的 core 的量.

内存 Memory

https://www.kernel.org/doc/Documentation/cgroup-v1/memory.txt
内存的限额使用 memory.limit_in_bytes 限制, 当前的使用量可以查看 memory.usage_in_bytes.

/sys/fs/cgroup/memory/docker/dfa566d/

文件系统

在 host 上面可以通过 /proc/<pid>/root/ 访问 container 里面的文件
或者可以通过 docker cp 命令来 copy 文件
在 container 里面访问 host 文件要在 container 里面加 volume 的方式