系列文章：
并发编程系列：关于线程中断
并发编程系列：阻塞队列的实现原理
一 背景
大家都知道，在服务/应用发布到预览或者线上环境时，经常会出现一些测试中没有出现的问题。并且由于环境所限，我们也不可能在线上调试代码，所以只能通过日志、系统信息和 dump 等手段来在线上定位问题。
通常需要借助一些工具，例如 jdk 本身提供的一些 jmap，jstack 等等，或者是阿里提供的比较强大的 Arthus，另外就是最基础的一些命令。根据经验，系统上发生的主要问题是在 cpu、内存、磁盘几个方面，因此会优先针对这类问题进行定位。由于绝大部分服务都是部署在 Linux 环境下，所以一下以 Linux 命令为例进行说明。
二 top 命令
top 命令可以用于查询每个进程的情况，显示信息如下：
top - 22:32:03 up 180 days, 7:23, 1 user, load average: 0.07, 0.06, 0.05Tasks: 106 total, 1 running, 105 sleeping, 0 stopped, 0 zombie%Cpu(s): 1.5 us, 1.0 sy, 0.0 ni, 97.5 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 stKiB Mem : 16266504 total, 324836 free, 6100252 used, 9841416 buff/cacheKiB Swap: 0 total, 0 free, 0 used. 9827120 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 1466 root 20 0 3243684 665836 14684 S 0.7 4.1 82:18.89 java 660 root 20 0 835120 25288 8036 S 0.3 0.2 718:10.90 exe 4835 root 20 0 6715536 129904 13368 S 0.3 0.8 400:01.40 java 8287 root 20 0 1003108 118464 18812 S 0.3 0.7 731:56.27 node /opt/my-ya 8299 root 20 0 1002164 107792 18816 S 0.3 0.7 730:11.28 node /opt/my-ya 8395 root 20 0 611552 35476 14504 S 0.3 0.2 14:17.25 node /opt/qkd-n 10184 root 20 0 3089652 673520 15880 S 0.3 4.1 83:32.81 java 12882 root 20 0 917540 64556 16156 S 0.3 0.4 543:55.74 PM2 v4.4.0: God 13556 root 20 0 2998424 556848 14548 S 0.3 3.4 496:48.18 java 14293 root 10 -10 151296 26920 6880 S 0.3 0.2 1868:03 AliYunDun 14755 root 20 0 3030352 676388 14720 S 0.3 4.2 49:16.41 java 22908 root 20 0 623456 38892 14536 S 0.3 0.2 98:50.65 node /opt/qkd-n 22936 root 20 0 622680 39712 14532 S 0.3 0.2 98:27.12 node /opt/qkd-n 24142 root 20 0 3303328 659496 14716 S 0.3 4.1 23:20.38 java 25566 root 20 0 706964 52660 16308 S 0.3 0.3 19:17.11 node /opt/qkd-n 25597 root 20 0 708020 53112 16308 S 0.3 0.3 19:06.83 node /opt/qkd-
复制代码
如上面内容所示，需要注意一下各列的含义，这里再重复一遍，如下表所示：
由于限定我们的应用是 Java 应用，所以只需要关注 COMMOND 列是 java 的进程信息。
有时候 %CPU 这列的数字可能会超过 100%，这不一定是出了问题，因为是机器所有核加在一起的 CPU 利用率，所以我们需要计算一下，平均每个核上的利用比例，再来确定是否是 CPU 使用过高，进而再去分析是否发生了死循环、内存回收等问题的可能。
在 top 命令出来的界面下，输入 1（top 的交互命令数字），可以查看每个 CPU 的性能信息：
top - 22:39:16 up 180 days, 7:30, 1 user, load average: 0.08, 0.06, 0.05Tasks: 106 total, 1 running, 105 sleeping, 0 stopped, 0 zombie%Cpu0 : 1.7 us, 1.3 sy, 0.0 ni, 97.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st%Cpu1 : 1.3 us, 1.0 sy, 0.0 ni, 97.7 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 stKiB Mem : 16266504 total, 324240 free, 6100720 used, 9841544 buff/cacheKiB Swap: 0 total, 0 free, 0 used. 9826652 avail Mem
复制代码
以上是我们某台机器上的实时数据，因为当前运行正常，所以没有异常数据。但看一下下面的数据：
命令行显示了 5 个 CPU，说明是一个 5 核的机器，平均每个 CPU 利用率在 60%以上。有时可能存在 CPU 利用率达到 100%，如果出现这种情况，那么很有可能是代码中写了死循环，继续看代码定位问题原因。
CPU 参数的含义如下：
交互命令 H，可以查看每个线程的性能信息：
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 5875 qkadmin 20 0 163144 3324 1612 R 1.0 0.0 0:00.24 top 1498 root 20 0 3243684 665836 14684 S 0.3 4.1 39:27.18 java 27412 root 20 0 3243684 665836 14684 S 0.3 4.1 15:14.25 java 4982 root 20 0 6715536 129904 13368 S 0.3 0.8 198:59.46 java 8287 root 20 0 1003108 118728 18812 S 0.3 0.7 688:11.51 node /opt/my-ya 10289 root 20 0 3089652 673520 15880 S 0.3 4.1 30:15.15 java 12261 root 20 0 803192 10800 4592 S 0.3 0.1 10:05.35 aliyun-service 12263 root 20 0 803192 10800 4592 S 0.3 0.1 5:45.73 aliyun-service 14351 root 20 0 2998424 556848 14548 S 0.3 3.4 1:14.78 java
复制代码
可能发生的几个问题和对应的现象有：
1、某个线程，CPU 利用率一直在 100%左右，那么说明这个线程很有可能出现死循环，记住这个 PID，并进一步定位具体应用；另外也可能是出现内存泄漏，触发频繁 GC 导致。这种情况，可以使用 jstat 命令查看 GC 情况，以分析是否持久代或老年代内存区域满导致触发 Full GC，进而使 CPU 利用率飙高，命令和显示信息如下(81443 是当前机器上观察的进程 id)：
jstat -gcutil 81443 1000 5
复制代码
信息：
S0 S1 E O M CCS YGC YGCT FGC FGCT GCT 0.00 53.94 78.77 0.05 97.26 93.39 1 0.006 0 0.000 0.006 0.00 53.94 78.77 0.05 97.26 93.39 1 0.006 0 0.000 0.006 0.00 53.94 78.77 0.05 97.26 93.39 1 0.006 0 0.000 0.006 0.00 53.94 78.77 0.05 97.26 93.39 1 0.006 0 0.000 0.006 0.00 53.94 78.77 0.05 97.26 93.39 1 0.006 0 0.000 0.006
复制代码
三 dump
下一步，可以把线程 dump 下来，然后再继续分析是哪个线程、执行到那段代码导致 CPU 利用率飙高。使用命令可以参考如下：
dump 文件内容：
192:dubbo-proxy-tools xxx$ cat dump01 2021-02-13 22:51:08Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.212-b10 mixed mode):
"Attach Listener" #14 daemon prio=9 os_prio=31 tid=0x00007f8cef903000 nid=0x1527 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE
"DestroyJavaVM" #12 prio=5 os_prio=31 tid=0x00007f8cef91d000 nid=0x2803 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE
"JPS event loop" #10 prio=5 os_prio=31 tid=0x00007f8cf1153800 nid=0xa703 runnable [0x0000700003656000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:117) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) - locked <0x00000007b5700798> (a io.netty.channel.nio.SelectedSelectionKeySet) - locked <0x00000007b57007b0> (a java.util.Collections$UnmodifiableSet) - locked <0x00000007b5700748> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at io.netty.channel.nio.SelectedSelectionKeySetSelector.select(SelectedSelectionKeySetSelector.java:62) at io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:753) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:408) at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:897) at java.lang.Thread.run(Thread.java:748)
"Service Thread" #9 daemon prio=9 os_prio=31 tid=0x00007f8cf3822800 nid=0x5503 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE
"C1 CompilerThread3" #8 daemon prio=9 os_prio=31 tid=0x00007f8cf1802800 nid=0x3a03 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE
"C2 CompilerThread2" #7 daemon prio=9 os_prio=31 tid=0x00007f8cf480c000 nid=0x3c03 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE
复制代码
线程 id （nid=0x2803） 是 16 进制，可与转成 10 进制，来跟 top 命令观察的 id 对应（可以简单地使用 printf "%x\n" 0x5503 即可）：
192:dubbo-proxy-tools xxxx$ printf "%x\n" 0x55035503
复制代码
2、某个线程一直在 top 10 的位置，那么说明该线程可能有性能问题
3、CPU 利用率高的线程不断变化，说明不是某一个线程导致的 CPU 利用率飙高
评论