现象
- 监控中tcp服务全部下线, 查询进程存在
- 主机cpu100%, 内存未溢出
分析
- cpu标高, top查看gc进程, 初步确定 Full GC引起
- Full GC 说明存在内存溢出问题
- 分析内存快照, 发现大量的下行消息堆积(81%), 说明下行阻塞, 可能是网络或者工作线程不足
- 其他服务反馈公网超时, 内网很快, 基本确定是网络原因
查看prometheus监控, 可以看到线程大量处于 waiting 状态(阻塞), 线程 waiting 导致下行消息堆积，内存增加(监控可见), 触发频繁 gc(监控可见), 频繁 gc 导致cpu load 及 使用率 升高(监控可见)
cpu飙高线程定位
- 使用top命令查看系统CPU的占用情况
1
2
3
4
5
6
7
8
9
10
| [csy@test-prd18-216 ~]$ top
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1882062 root 20 0 5821124 990.2m 39440 S 3.0 6.3 517:35.57 java
2414864 root 20 0 6705196 928780 43040 S 2.7 5.7 18:31.56 java
2219736 root 20 0 6828528 1.2g 42508 S 2.3 7.7 173:44.09 java
74679 kibana 20 0 1390224 539292 42592 S 1.7 3.3 1746:25 node
2348141 root 20 0 6782016 1.1g 41196 S 1.7 7.0 58:10.43 java
1954780 root 20 0 6714380 946000 42648 S 1.3 5.8 187:26.73 java
286946 root 20 0 6635204 862820 37900 S 0.7 5.3 403:58.62 java
1871394 root 20 0 6706500 926456 35656 S 0.7 5.7 111:34.88 java
|
- 查看该进程的各个线程运行情况
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
| [csy@test-prd18-216 ~]$ top -Hp 1882062
top - 15:06:05 up 77 days, 4:47, 1 user, load average: 0.40, 0.24, 0.18
Threads: 179 total, 0 running, 179 sleeping, 0 stopped, 0 zombie
%Cpu(s): 1.0 us, 0.4 sy, 0.0 ni, 98.2 id, 0.0 wa, 0.4 hi, 0.0 si, 0.0 st
MiB Mem : 15830.8 total, 430.5 free, 8943.2 used, 6457.1 buff/cache
MiB Swap: 0.0 total, 0.0 free, 0.0 used. 6967.2 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1882103 root 20 0 5821124 990.2m 39440 S 0.3 6.3 45:55.15 Log4j2-TF-1-Asy
1882145 root 20 0 5821124 990.2m 39440 S 0.3 6.3 0:26.77 es-connection-t
1882175 root 20 0 5821124 990.2m 39440 S 0.3 6.3 20:00.96 MOBILE_CHECK_LI
1882193 root 20 0 5821124 990.2m 39440 S 0.3 6.3 18:55.50 VISITOR_FULL_LI
1882194 root 20 0 5821124 990.2m 39440 S 0.3 6.3 9:22.17 kafka-coordinat
1882083 root 20 0 5821124 990.2m 39440 S 0.0 6.3 0:00.00 java
1882063 root 20 0 5821124 990.2m 39440 S 0.0 6.3 0:14.28 java
1882064 root 20 0 5821124 990.2m 39440 S 0.0 6.3 3:01.71 GC Thread#0
1882065 root 20 0 5821124 990.2m 39440 S 0.0 6.3 0:00.00 G1 Main Marker
1882066 root 20 0 5821124 990.2m 39440 S 0.0 6.3 0:00.00 G1 Conc#0
1882067 root 20 0 5821124 990.2m 39440 S 0.0 6.3 0:00.02 G1 Refine#0
1882068 root 20 0 5821124 990.2m 39440 S 0.0 6.3 9:01.27 G1 Young RemSet
1882069 root 20 0 5821124 990.2m 39440 S 0.0 6.3 4:18.25 VM Thread
1882070 root 20 0 5821124 990.2m 39440 S 0.0 6.3 0:00.01 Reference Handl
1882071 root 20 0 5821124 990.2m 39440 S 0.0 6.3 0:00.00 Finalizer
1882072 root 20 0 5821124 990.2m 39440 S 0.0 6.3 0:00.00 Signal Dispatch
1882073 root 20 0 5821124 990.2m 39440 S 0.0 6.3 1:29.21 C2 CompilerThre
1882074 root 20 0 5821124 990.2m 39440 S 0.0 6.3 0:16.32 C1 CompilerThre
|
说明:
1
2
3
4
5
6
7
8
| us：用户进程空间中未改变过优先级的进程占用CPU百分比
sy：内核空间占用CPU百分比
ni：用户进程空间内改变过优先级的进程占用CPU百分比
id：空闲时间百分比
wa：空闲&等待I/O的时间百分比
hi：硬中断时间百分比
si：软中断时间百分比
st：虚拟化时被其余VM窃取时间百分比
|
Load高 & CPU高
这是我们最常遇到的一类情况，即load上涨是CPU负载上升导致。根据CPU具体资源分配表现，可分为以下几类：
CPU sys高
这种情况CPU主要开销在于系统内核，可进一步查看上下文切换情况。
如果非自愿上下文切换较多，说明CPU抢占较为激烈，大量进程由于时间片已到等原因，被系统强制调度，进而发生的上下文切换。
如果自愿上下文切换较多，说明可能存在I/O、内存等系统资源瓶颈，大量进程无法获取所需资源，导致的上下文切换。
CPU si高
这种情况CPU大量消耗在软中断，可进一步查看软中断类型。一般而言，网络I/O或者线程调度引起软中断最为常见：
NET_TX & NET_RX。NET_TX是发送网络数据包的软中断，NET_RX是接收网络数据包的软中断，这两种类型的软中断较高时，系统存在网络I/O瓶颈可能性较大。
SCHED。SCHED为进程调度以及负载均衡引起的中断，这种中断出现较多时，系统存在较多进程切换，一般与非自愿上下文切换高同时出现，可能存在CPU瓶颈。
CPU us高
这种情况说明资源主要消耗在应用进程，可能引发的原因有以下几类：
死循环或代码中存在CPU密集计算。这种情况多核CPU us会同时上涨。
内存问题，导致大量FULLGC，阻塞线程。这种情况一般只有一核CPU us上涨。
资源等待造成线程池满，连带引发CPU上涨。这种情况下，线程池满等异常会同时出现。
Load高 & CPU低
这种情况出现的根本原因在于不可中断睡眠态(TASK_UNINTERRUPTIBLE)进程数较多，即CPU负载不高，但I/O负载较高。可进一步定位是磁盘I/O还是网络I/O导致。
- 线程id都转换成十六进制形式, 即线程快照中的 0x1cb7e3
1
2
| [csy@test-prd18-216 ~]$ printf "%x\n" 1882083
1cb7e3
|
- 根据进程和线程在线程快照查找原因: nid=0x1cb7e3
1
| jstack 1882062 |grep 1cb7e3
|
