详解 Java 线上问题排查思路

原创

宫水三叶的刷题日记

修改于 2021-03-02 18:09:52

3.1K0

修改于 2021-03-02 18:09:52

文章被收录于专栏：宫水三叶的刷题日记宫水三叶的刷题日记

前言

针对各种常见的线上问题，梳理下排查思路。

测试环境搭建

既然要模拟排查线上问题，就不能使用本地环境。

至少是个 Linux 操作系统，最好还是个纯粹的 Java 环境。

所以直接使用 docker 搭建最为方便：

打开一个窗口（窗口 A），拉取 openjdk 镜像：

docker?pull?openjdk:8-jdk

启动容器，挂载一个数据卷，方便我们本地修改代码，然后在容器内运行：

docker?run?-it?-v?your/path/floder/:/folder/?openjdk:8-jdk?/bin/bash

在挂载数据卷下，编写 Main.java 文件（之后模拟的线上问题代码会编写在此文件），然后在容器内编译执行：

cd?folder/
javac?Main.java
java?-Xms50M?-Xmx50M?-XX:+PrintGC?Main

打开另外一个窗口（窗口 B），进入容器，用于监控容器状况：

docker?exec?-it?container_id?/bin/bash

CPU 问题

导致线上 CPU 吃满通常是线程过多或者线程“死锁”，一般而言后者的可能性更大。

因为通常线程数量会由线程池管理，一般不会超过我们设定的最大值；而线程“死锁”通常是人为代码问题，某个获得锁的线程没有释放锁，导致其他线程一直处于 Waiting 状态（或者 CAS 自旋状态）。

模拟线程过多导致的 CPU 问题

修改 Main.java 文件如下，并在窗口 A 重新编译运行 Main ：

public?class?Main?{
????public?static?void?main(String[]?args)?{
????????final?int?count?=?1000;
????????ExecutorService?threadPool?=?Executors.newFixedThreadPool(count);
????????for?(int?i?=?0;?i?<?count;?i++)?{
????????????threadPool.submit(new?Runnable()?{
????????????????@Override
????????????????public?void?run()?{
????????????????????for?(;;)?{
????????????????????????try?{
????????????????????????????//?模拟耗时操作
????????????????????????????Thread.sleep(50);
????????????????????????}?catch?(InterruptedException?e)?{
????????????????????????????e.printStackTrace();
????????????????????????}
????????????????????}
????????????????}
????????????});
????????}
????}
}

定位线程过多导致的 CPU 问题

top 命令：查看哪个进程占用 CPU 过高。定位到 pid （7610）

top -Hp pid 命令：查看问题进程中的线程情况。可以看到 Threads: 1012 total, 0 running, 1012 sleeping, 0 stopped, 0 zombie ：

可见 CPU 过高原因是过多线程正在处于 SLEEPING 状态。而且每个线程的 CPU 占比和内存占比都差不多，我们随便找一个线程进行分析。PID 为 7622 的线程。

jstack pid | grep nid -C10 ：查看对应的线程前后 10 行的状态信息（注意，先使用 `printf '%x\n' nid 或者其他方式，将十进制的 nid 转换为十六进制的 nid）:

打印出的线程堆栈可以发现是在 Main.java 中的第 19 当导致的线程进入 SLEEPING 状态，其他的导致线程 TIMED_WAITING 甚至 BLOCKED 的原因也可以通过分析堆栈得出原因。这里的堆栈分析方法和我们常规的分析方法是一样的。

解决方案

解决线程过多问题，首先不能使用由 Executors 工具类提供的 newCachedThreadPool() 方法，因为查看源码就可以知道该方法所指定 maximumPoolSize 参数为 Integer.MAX_VALUE 。

也就是在高并发场景下，会不断的创建线程。会引发线程过多，导致 CPU 吃满问题。

事实上，除了 newCachedThreadPool() 以外，其他的如 newFixedThreadPool 、newSingleThreadExecutor 也不应该在生产上使用，因为这些内置线程池都是使用 LinkedBlockingQueue 作为任务队列，LinkedBlockingQueue属于“无界”队列，在高并发场景下会导致 OOM 。

所以使用线程池的最佳实践是自己调用 ThreadPoolExecutor 的构造方法：

指定合适的 maximumPoolSize 参数，防止过多的线程创建；
使用?ArrayBlockingQueue?等“有界”队列，防止 OOM；
自定义 ThreadFactory?（为了给线程起名字），方便以后的 GC 日志排查。

通过这一个小例子，可以发现当线上出现 CPU 过高问题时，可以先通过 top 命令定位到问题进程的 id（如果是微服务，即当前服务器对应的 java 进程很少，百分百就确定是某个应用时，也可以通过 jps 直接取得进程 id ）；

然后使用 top -Hp pid 查看问题进程中的线程 CPU 占用情况，分析是某个线程占用 CPU 过高还是线程过多导致，定位线程 nid，并转换为十六进制；

使用 jstack pid | grep nid -C10 命令查看与 nid 对应的线程的状态信息和该线程的堆栈信息（主要是自身程序代码的堆栈信息），也可以使用 jstack -l nid 命令查看更详细的线程堆栈信息（主要是 JDK 方法调用的堆栈信息）。

模拟线程“锁等待”导致的 CPU 问题

修改 Main.java 文件如下，并在窗口 A 重新编译运行 Main ：

public?class?Main?{
????public?static?void?main(String[]?args)?{
????????final?int?count?=?10;
????????final?ReentrantLock?lock?=?new?ReentrantLock();
????????ExecutorService?threadPool?=?Executors.newFixedThreadPool(count,?new?ThreadFactory()?{
????????????????????@Override
????????????????????public?Thread?newThread(Runnable?r)?{
????????????????????????Thread?thread?=?new?Thread(r);
????????????????????????thread.setName("PETERXX_PROJECT_POOL_"?+?UUID.randomUUID().toString());
????????????????????????return?thread;
????????????????????}
????????????????}
????????);
????????for?(int?i?=?0;?i?<?count;?i++)?{
????????????threadPool.submit(new?Runnable()?{
????????????????@Override
????????????????public?void?run()?{
????????????????????for?(;?;?)?{
????????????????????????lock.lock();
????????????????????????for?(int?j?=?0;?j?<?100_0000;?j++)?{

????????????????????????}
????????????????????????lock.unlock();
????????????????????}
????????????????}
????????????});
????????}
????}
}

这次虽然只起 10 个线程，每个线程都是「循环执行获得锁操作，计数 100w 次，释放锁的过程」。

由于使用的 ReentrantLock（CAS），所以每次除成功获取锁的线程以外，其他线程都在自旋（内部也是使用 for(;;) 的方式），所以导致 CPU 过高。

另外我们通过自定义 ThreadFactory 的方式为线程池中的线程进行命名（主要是为了之后的方面定位线程），我们尝试使用前面总结的思路来定位问题。

定位线程“锁等待”导致的 CPU 问题

可以使用 top 命令来定位问题进程的 pid ，但由于我们使用的纯粹的 docker 环境，也只运行了一个 java 进程，我们这里直接使用 jps 命令来定位进程：

root@436f6af3feeb:/#?jps
8992?Jps
8925?Main

还是使用 top -Hp pid 的方式，查看线程占用情况，发现只有三个线程处于 RUNNABLE 状态，其余线程处于 SLEEPING 状态。而且线程占用 CPU 资源情况不一，CPU 占用时高时低，这时候其实就相当于没法定位到具体某个线程的 id 了：

由于这次没有特定的线程 id ，可以直接执行 jstack pid 指令来大概看一眼各线程的状态（下面输出进行了部分删减）：

root@436f6af3feeb:/#?jstack?8925
...
"PETERXX_PROJECT_POOL_31d60b05-41e9-4100-9068-93ed5edc2ab5"?#17?prio=5?os_prio=0?tid=0x00007fa42810c800?nid=0x2489?waiting?on?condition?[0x00007fa4125c7000]
???java.lang.Thread.State:?WAITING?(parking)
?at?sun.misc.Unsafe.park(Native?Method)
?-?parking?to?wait?for??<0x00000000fefdbca8>?(a?java.util.concurrent.locks.ReentrantLock$NonfairSync)
?at?java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
?at?java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
?at?java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
?at?java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
?at?java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
?at?java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
?at?Main$2.run(Main.java:26)
?at?java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
?at?java.util.concurrent.FutureTask.run(FutureTask.java:266)
?at?java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
?at?java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
?at?java.lang.Thread.run(Thread.java:748)

"PETERXX_PROJECT_POOL_efb3edf0-886a-4abb-b6fe-cf3dbdcb31b4"?#16?prio=5?os_prio=0?tid=0x00007fa42810a800?nid=0x2488?runnable?[0x00007fa4126c8000]
???java.lang.Thread.State:?WAITING?(parking)
?at?sun.misc.Unsafe.park(Native?Method)
?-?parking?to?wait?for??<0x00000000fefdbca8>?(a?java.util.concurrent.locks.ReentrantLock$NonfairSync)
?at?java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
?at?java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
?at?java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
?at?java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
?at?java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
?at?java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
?at?Main$2.run(Main.java:26)
?at?java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
?at?java.util.concurrent.FutureTask.run(FutureTask.java:266)
?at?java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
?at?java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
?at?java.lang.Thread.run(Thread.java:748)
...
"PETERXX_PROJECT_POOL_739c1a07-46f6-4f4f-9ecf-8373fb2c0e70"?#13?prio=5?os_prio=0?tid=0x00007fa428105800?nid=0x2485?runnable?[0x00007fa4129cb000]
???java.lang.Thread.State:?RUNNABLE
?at?Main$2.run(Main.java:30)
?at?java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
?at?java.util.concurrent.FutureTask.run(FutureTask.java:266)
?at?java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
?at?java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
?at?java.lang.Thread.run(Thread.java:748)
?
"Service?Thread"?#7?daemon?prio=9?os_prio=0?tid=0x00007fa4280ba800?nid=0x247e?runnable?[0x0000000000000000]
???java.lang.Thread.State:?RUNNABLE
...

可以发现有较多线程处于 WAITING 状态，只有较少数线程处于 RUNNABLE 状态。

由于之前我们对线程进行了命名，可以使用 jstack pid | grep PETERXX_PROJECT_POOL 对线名称进行过滤：

root@436f6af3feeb:/#?jstack?8925?|?grep?PETERXX_PROJECT_POOL
"PETERXX_PROJECT_POOL_31d60b05-41e9-4100-9068-93ed5edc2ab5"?#17?prio=5?os_prio=0?tid=0x00007fa42810c800?nid=0x2489?runnable?[0x00007fa4125c7000]
"PETERXX_PROJECT_POOL_efb3edf0-886a-4abb-b6fe-cf3dbdcb31b4"?#16?prio=5?os_prio=0?tid=0x00007fa42810a800?nid=0x2488?waiting?on?condition?[0x00007fa4126c8000]
"PETERXX_PROJECT_POOL_037b173d-f28e-4a80-b98c-7fb875882f73"?#15?prio=5?os_prio=0?tid=0x00007fa428109000?nid=0x2487?waiting?on?condition?[0x00007fa4127c9000]
"PETERXX_PROJECT_POOL_efdc4d85-5735-4a04-bdd3-a47205539040"?#14?prio=5?os_prio=0?tid=0x00007fa428107800?nid=0x2486?runnable?[0x00007fa4128ca000]
"PETERXX_PROJECT_POOL_739c1a07-46f6-4f4f-9ecf-8373fb2c0e70"?#13?prio=5?os_prio=0?tid=0x00007fa428105800?nid=0x2485?waiting?on?condition?[0x00007fa4129cb000]
"PETERXX_PROJECT_POOL_fcc7d04c-a5f2-4be3-920a-ddc36fbfd9b1"?#12?prio=5?os_prio=0?tid=0x00007fa428104000?nid=0x2484?runnable?[0x00007fa412acc000]
"PETERXX_PROJECT_POOL_b17d1f19-bbf3-43cb-96a5-27eef6c46f0d"?#11?prio=5?os_prio=0?tid=0x00007fa428102000?nid=0x2483?waiting?on?condition?[0x00007fa412bcd000]
"PETERXX_PROJECT_POOL_42f75df3-c9cb-4031-bad5-670079e68b34"?#10?prio=5?os_prio=0?tid=0x00007fa428100800?nid=0x2482?waiting?on?condition?[0x00007fa412cce000]
"PETERXX_PROJECT_POOL_811769a4-ade2-4113-b644-235fb1d7c80f"?#9?prio=5?os_prio=0?tid=0x00007fa4280ff000?nid=0x2481?waiting?on?condition?[0x00007fa412dcf000]
"PETERXX_PROJECT_POOL_def0c7fd-c171-4356-9029-52ec793b3a37"?#8?prio=5?os_prio=0?tid=0x00007fa4280fd000?nid=0x2480?waiting?on?condition?[0x00007fa412ed0000]

可以看到只有少数线程处于 RUNNABLE 状态，其余都是处于 WAITING 状态。基本上可以判断是锁等待导致的。

这时候我们可以找一个处于 RUNNABLE 状态的 nid 查看堆栈：

root@436f6af3feeb:/#?jstack?8925?|?grep?0x2489?-C10
"PETERXX_PROJECT_POOL_31d60b05-41e9-4100-9068-93ed5edc2ab5"?#17?prio=5?os_prio=0?tid=0x00007fa42810c800?nid=0x2489?runnable?[0x00007fa4125c7000]
???java.lang.Thread.State:?RUNNABLE
?at?Main$2.run(Main.java:26)
?at?java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
?at?java.util.concurrent.FutureTask.run(FutureTask.java:266)
?at?java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
?at?java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
?at?java.lang.Thread.run(Thread.java:748)
...

找一个处于 WAITING 状态的 nid 查看堆栈：

root@436f6af3feeb:/#?jstack?9332?|?grep?0x2483?-C10
"PETERXX_PROJECT_POOL_b17d1f19-bbf3-43cb-96a5-27eef6c46f0d"?#11?prio=5?os_prio=0?tid=0x00007fa428102000?nid=0x2483?waiting?on?condition?[0x00007fa412bcd000]
???java.lang.Thread.State:?WAITING?(parking)
?at?sun.misc.Unsafe.park(Native?Method)
?-?parking?to?wait?for??<0x00000000ffc00c18>?(a?java.util.concurrent.locks.ReentrantLock$NonfairSync)
?at?java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
?at?java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
?at?java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
?at?java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
?at?java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
?at?java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
?at?Main$2.run(Main.java:26)
...

可以看到处于 WAITING 的线程在 Main.java 的 26 行开始等待地址为 <0x00000000ffc00c18> 的 ReentrantLock$NonfairSync 锁对象，而处于 RUNNABLE 状态的线程是在 Main.java 的 26 行开始执行，到这里基本可以确定是哪个类的哪个方法用到的锁没有及时释放导致过多线程处于“锁等待”状态，最终导致 CPU 过高问题。

解决方案

因为“锁等待”导致 CPU 过高问题，一般是因为使用的 CAS 锁（尝试获取 CAS 锁的进程会在死循环中不断请求锁），同时占用锁资源的线程没有及时把锁释放（占用锁资源的线程的任务耗时过长）。

针对这种情况可以将 CAS 锁替换为 synchronized ，因为 synchronized 存在“锁升级”过程，会将占用 CPU 资源的轻量级锁升级为不占用 CPU 资源的重量级锁。

模拟频繁 GC 导致的 CPU 问题

修改 Main.java 文件如下，并在窗口 A 重新编译运行 Main ：

public?class?Main?{
????public?static?void?main(String[]?args)?{
????????for?(int?i?=?0;?i?<?10;?i++)?{
????????????new?Thread(new?Runnable()?{
????????????????@Override
????????????????public?void?run()?{
????????????????????for?(;;)?{
????????????????????????WeakReference<byte[]>?weakReference?=?new?WeakReference<>(new?byte[1024?*?1024]);
????????????????????}
????????????????}
????????????}).start();
????????}
????}
}

一个死循环，会不断的在堆上创建大小为 1M 的对象，同时由于使用的弱引用，可以确保达到「堆空间不断被占用，触发 GC，而 GC 后堆内存又能够被释放（即堆内存占用会持续升高，但不会导致 OOM）的效果」。

定位频繁 GC 导致的 CPU 问题

其实如果是 GC 导致的 CPU 问题，是很好定位的。按照我们之前的思路：先使用 top 定位到问题进程、 top -Hp pid 查看问题进程中的线程情况，如果是频繁 GC 导致的 CPU 问题，到这一步应该会看到 GC 线程会吃满了 CPU：

解决方案

如果是 GC 导致的 CPU 问题，一般是通过分析堆内存 dump 文件进行分析。

换句话说「频繁 GC 导致的 CPU 问题，通常是先引发的 OOM 内存问题导致的，解决了根本的内存问题，也就解决了频繁 GC 导致的 CPU 问题。」

内存问题

要解决内存问题，需要先想办法查看进程内存使用情况。

通常在生产上有两个参数是必须开启的：-XX:+HeapDumpAfterFullGC & -XX:+HeapDumpOnOutOfMemoryError，可以确保系统发生 FGC 和 OOM 的时候将 Java 堆的状况记录下来，便于分析。

在线定位（原生命令）

jstat -gc pid

查看 pid 对应的 Java 进程当前情况下的 GC 情况：

$?jstat?-gc?pid
?S0C????S1C????S0U????S1U??????EC???????EU????????OC?????????OU???????MC?????MU????CCSC???CCSU???YGC?????YGCT????FGC????FGCT?????GCT
1024.0?1024.0??0.0????0.0????8704.0???4368.9???22016.0??????0.0?????4480.0?778.9??384.0???74.6???????0????0.000???0??????0.000????0.000

S0C、S1C、S0U、S1U ：两个 Survivor 区的容量和使用量

EC、EU ：Eden 区的容量和使用量

MC、MU ：方法区的容量和使用量

YGC、YGCT ：YGC 的次数和耗时

FGC、FGCT ：FGC 的次数和耗时

GCT ：GC 的总耗时

jinfo

jinfo -flags pid ：查看 ?pid 对应的 JVM 的参数

jinfo -sysprops pid ：查看当前系统参数包括 -D 设置的参数

$?jinfo?-flag?GCLogFileSize?pid
-XX:GCLogFileSize=8192

jmap

jmap pid ：查看进程中的内存映像信息。将会打印目标虚拟机中加载的每个共享对象的起始地址、映射大小以及共享文件的路径全称。
jmap -heap pid ：显示 Java 堆详细信息。打印堆的摘要信息，包括 GC 算法，堆配置信息和各个分代的使用情况。

$?jmap?-heap?pid
Attaching?to?process?ID?pid,?please?wait...
Debugger?attached?successfully.
Server?compiler?detected.
JVM?version?is?25.131-b11

##?使用的?GC?回收器
using?thread-local?object?allocation.
Parallel?GC?with?10?thread(s)

##?当前?Heap?配置信息
Heap?Configuration:
???MinHeapFreeRatio?????????=?0
???MaxHeapFreeRatio?????????=?100
???MaxHeapSize??????????????=?4294967296?(4096.0MB)
???NewSize??????????????????=?89128960?(85.0MB)
???MaxNewSize???????????????=?1431306240?(1365.0MB)
???OldSize??????????????????=?179306496?(171.0MB)
???NewRatio?????????????????=?2
???SurvivorRatio????????????=?8
???MetaspaceSize????????????=?21807104?(20.796875MB)
???CompressedClassSpaceSize?=?1073741824?(1024.0MB)
???MaxMetaspaceSize?????????=?17592186044415?MB
???G1HeapRegionSize?????????=?0?(0.0MB)

##?当前堆内存使用情况（各个分代的总容量/已使用/空闲）
Heap?Usage:
PS?Young?Generation
Eden?Space:
???capacity?=?67108864?(64.0MB)
???used?????=?40373512?(38.50318145751953MB)
???free?????=?26735352?(25.49681854248047MB)
???60.16122102737427%?used
From?Space:
???capacity?=?11010048?(10.5MB)
???used?????=?1277952?(1.21875MB)
???free?????=?9732096?(9.28125MB)
???11.607142857142858%?used
To?Space:
???capacity?=?11010048?(10.5MB)
???used?????=?0?(0.0MB)
???free?????=?11010048?(10.5MB)
???0.0%?used
PS?Old?Generation
???capacity?=?179306496?(171.0MB)
???used?????=?8192?(0.0078125MB)
???free?????=?179298304?(170.9921875MB)
???0.004568713450292397%?used

1256?interned?Strings?occupying?87960?bytes.

jmap -histo pid ：显示 Java 堆中的对象的统计信息。包括每个类的对象数量、所占内存大小等。可配合管道使用

$?jmap?-histo?pid?|?head?-20

##?编号???实例数量????????????占用大小??类名
?num?????#instances?????????#bytes??class?name
----------------------------------------------
???1:???????????697?????????544360??[I
???2:??????????3480?????????274920??[C
???3:???????????322?????????119400??[B
???4:???????????629??????????71848??java.lang.Class
???5:??????????2605??????????62520??java.lang.String
???6:???????????876??????????47568??[Ljava.lang.Object;
???7:???????????130???????????9360??java.lang.reflect.Field
...

jmap -clstats pid ：打印类加载器信息

$?jmap?-clstats?pid
Attaching?to?process?ID?77pid221,?please?wait...
Debugger?attached?successfully.
Server?compiler?detected.
JVM?version?is?25.131-b11
finding?class?loader?instances?..done.
computing?per?loader?stat?..done.
please?wait..?computing?liveness.liveness?analysis?may?be?inaccurate?...
class_loader?classes?bytes?parent_loader?alive??type

##?Bootstrap?加载器/?Ext?拓展加载器?/?APP?加载器
<bootstrap>?566?1151677???null???live?<internal>
0x00000006c67956a0?20?63212?0x00000006c679f210?dead?sun/misc/Launcher$AppClassLoader@0x00000007c000f6a0
0x00000006c679f210?0?0???null???dead?sun/misc/Launcher$ExtClassLoader@0x00000007c000fa48

total?=?3?586?1214889?????N/A?????alive=1,?dead=2?????N/A

jmap -finalizerinfo pid ：打印等待 GC 的对象的信息

$?jmap?-clstats?pid
Attaching?to?process?ID?pid,?please?wait...
Debugger?attached?successfully.
Server?compiler?detected.
JVM?version?is?25.131-b11
Number?of?objects?pending?for?finalization:?0

jmap -dump:live,format=b,file=filename pid ：将 pid 对应的 Java 进程中的内存使用情况以 .hprof 文件形式保存到本地，方便我们本地分析。

在线定位（Arthas 工具）

Arthas 是阿里开源的 Java 诊断工具。Arthas 还提供了在线工具学习工具，帮助快速上手。

下面记录一下 Arthas 的常用功能：

在开始之前，先下载 arthas-boot.jar 包，直接通过 java -jar 命令启动，然后会让列出所有正在运行的 java 进程，让用户选择需要监控的进程，之后会进入 Arthas 的操作界面。

dashboard 命令

在操作界面输入 dashboard 命令，可以看到所监控的进程的所有线程信息（线程 ID、名称、状态、占用 CPU 情况、占用内存情况、是否为守护线程等等）、内存信息（堆内存、Eden 区、Survivor 区、老年代、方法区）、以及机器情况：

sysporp / sysenv 命令

通过 sysporp 命令可以查看所有的 System Properties 信息。

通过 sysenv 命令可以查看所有的环境变量信息。

JVM 命令

查看当前的进程使用的 JVM 参数。

thread 命令

在知道了线程 id 之后，可以通过 thread thread_id 的方式查看某个线程正在执行的堆栈信息。

例如 thread 1 可以查看主线程的堆栈信息：

$?thread?1
"main"?Id=1?TIMED_WAITING
????at?java.lang.Thread.sleep(Native?Method)
????at?java.lang.Thread.sleep(Thread.java:340)
????at?java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
????at?demo.MathGame.main(MathGame.java:17)

sc 命令

通过 sc 命令可以查看已经加载过的类的信息：

$?sc?-d?*MathGame
?class-info????????demo.MathGame
?code-source???????/arthas-demo.jar
?name??????????????demo.MathGame
?isInterface???????false
?isAnnotation??????false
?isEnum????????????false
?isAnonymousClass??false
?isArray???????????false
?isLocalClass??????false
?isMemberClass?????false
?isPrimitive???????false
?isSynthetic???????false
?simple-name???????MathGame
?modifier??????????public
?annotation
?interfaces
?super-class???????+-java.lang.Object
?class-loader??????+-sun.misc.Launcher$AppClassLoader@70dea4e
?????????????????????+-sun.misc.Launcher$ExtClassLoader@71b5ca3a
?classLoaderHash???70dea4e

sm 命令

通过 sm 类名的方式可以获取类的所有函数，添加 -d 可以获取详细的函数信息，也可以指定查看某个函数：

$?sm?java.math.RoundingMode
java.math.RoundingMode?<init>(Ljava/lang/String;II)Vjava.math.RoundingMode?values()[Ljava/math/RoundingMode;
java.math.RoundingMode?valueOf(I)Ljava/math/RoundingMode;
java.math.RoundingMode?valueOf(Ljava/lang/String;)Ljava/math/RoundingMode;

$?sm?-d?java.math.RoundingMode
?declaring-class???java.math.RoundingMode
?constructor-name??<init>
?modifier??????????private
?annotation
?parameters????????java.lang.String
???????????????????int
???????????????????int
?exceptions
?classLoaderHash???null
?
?declaring-class??java.math.RoundingMode
?method-name??????values
?modifier?????????public,static
?annotation
?parameters
?return???????????java.math.RoundingMode[]
?exceptions
?classLoaderHash??null
?...
?
$?sm?-d?java.math.RoundingMode?<init>
?declaring-class???java.math.RoundingMode
?constructor-name??<init>
?modifier??????????private
?annotation
?parameters????????java.lang.String
???????????????????int
???????????????????int
?exceptions
?classLoaderHash???null

jad 命令

通过 jad 命令可以进行反编译代码，该功能可以帮助我们查看动态代理生成了什么样的类（例如先通过 sc + 通配的方式定位到某个类，再通过 jad 命令反编译得出该类的代码）：

$?jad?demo.MathGame
//?省略...

watch 命令

通过 watch 命令可以查看当前函数的参数/返回值/异常信息：

$?watch?demo.MathGame?primeFactors?returnObj
Press?Q?or?Ctrl+C?to?abort.
Affect(class?count:?1?,?method?count:?1)?cost?in?42?ms,?listenerId:?2
ts=2019-12-14?06:06:25;?[cost=0.1876ms]?result=null
ts=2019-12-14?06:06:26;?[cost=0.1316ms]?result=@ArrayList[
????@Integer[3],
????@Integer[173],
????@Integer[307],
]
...

ognl 命令

用于动态执行代码，在当前线程环境中执行代码：

$?ognl?'@java.lang.System@out.println("hello?ognl")'

redefine 命令

使用 redefine /path/xxx.class 的方式，能重新加载编译好的类。通常可以很方便的实现一些热修复。其实和 IDEA 中 tomcat 的热部署原理一样，就是用 ClasssLoader 重新 load 一遍修改的类。

事后分析（jhat 命令）

对于生产系统，其实能够进行在线定位的机会并不多。

主要是因为一直对发生问题的机器采用在线定位的手段的话，会影响该机器的业务性能；如果将该机器和集群隔离开来再进行在线定位的话，流量下去之后往往问题也消失了。

一般对于线上问题，都是采用这样的步骤：

先将机器和集群隔离开来
马上调用 jmap -dump 命令将 Java 堆的现场情况保存下来
对问题机器中的进程进行重启，恢复上线
将保存下来的 dump 文件导到本地进行分析

可直接使用 jhat [options] heap-dump-file 命令对 heap dump file 进行分析，其中 Options 参数有：

-stack ：false | true。是否跟踪对象分配调用栈，默认值为 true。
-refs ：false | true。是否跟踪对象引用，默认值为 true。
-port ：jhat HTTP server 的端口号，默认值 7000。
-exclude ：文件路径。指定对象查询时需要排除的数据成员列表文件。
-baseline ：文件路径。指定一个基准堆转储，在两个 heap dumps 中有相同 object ID 的对象会被标记为不是新的。
-debug ：debug 级别，值越大则表示输出更详细的 debug 信息。默认为 0 。

$?jhat?heapdump.hprof
Snapshot?read,?resolving...
Resolving?447484?objects...
Chasing?references,?expect?89?dots?......................
Eliminating?duplicate?references?......................
Snapshot?resolved.
Started?HTTP?server?on?port?7000
Server?is?ready.

然后访问本地的 7000 的端口，是一个包含 Java 堆信息的分析网页：

Package <Default Package> 中包含了我们自己写的包下的类的使用情况。
All classes including platform ：所有的类，包含平台启动创建的类
Show all members of the rootset ：所有根对象可以连接到的成员，也就是不会被 GC 回收的对象
Show instance counts for all classes (including platform) |(excluding platform) 【重要】：查看什么类有多少实例数量（包含平台的 | 不包含平台的）
Show heap histogram 【重要】：以列表的形式展示什么类有多少实例数量，占用了多少内存
Finalizer Summary ：等待被调用 finalize() 方法的对象，在对象被 GC 回收前，会被调用一次 finalize() 方法（可在方法中重新将该对象和 GC Roots 对象进行关联，实现对象重生）。
Object Query Language (OQL) query 【重要】：使用 OQL （类似 SQL）对堆内存信息进行过滤查询

事后分析（Java VisualVM 工具）

在 Mac 系统下，需要在 IDEA 中安装 ?VisualVM Launcher 插件并配置相关路径，然后装入 dump 文件。

通过可视化界面查看 dump 文件中记录所使用的类：

以及每个类有多少实例对象（以 500 个为单位进行显示）：

仅仅是这两个界面，基本上我们就能大概了解到 dump 文件都记录了什么内容，以及是哪些类创建了较多实例，占用了较大的内存。

Java VisualVM 除了能分析 dump 文件以外，还能进行实时的可视化监控分析。但使用 Java VisualVM 会占用较多资源，所以一般线上环境中不会使用，实在要在线定位问题的话，生产上通常选择前面说到的 Arthas + 原生命令（主要是 jmap 命令）的方式进行。

虽然在生产上使用有性能问题，但在上线前的测试环境压测，使用 Java VisualVM 进行监控还是十分方便：

监控 CPU 、堆、类加载情况和线程数量：

查看线程调度情况：

原创声明：本文系作者授权腾讯云开发者社区发表，未经许可，不得转载。

如有侵权，请联系 cloudcommunity@tencent.com 删除。

java

原创声明：本文系作者授权腾讯云开发者社区发表，未经许可，不得转载。

如有侵权，请联系 cloudcommunity@tencent.com 删除。

java