记: 服务器卡顿排查

背景：近期业务使用的一台40核、157GB的服务器不定期会出现卡顿，需要确认问题问题原因
排查：

使用top命令查看当前状态

image.png

内存占用91%, 参考往期内存占用, 当前数值符合预期 (过)
load average, 系统平均负载, 1、5、15分钟内平均进程数在60上下, 40核平摊下来单个CPU平均负载在1.5 (过)
Tasks: 2192 total, 6 running, 2184 sleeping, 0 stopped, 2 zombie 处于running状态的进程数远不及预期 (待排查)
Cpu(s): 43.0%wa, %wa为等待输入输出的CPU时间百分比, 这项也有点高, 按理说2000+的进程数不能有这么高的等待时间 (待排查)

使用top命令查看各CPU状态

image.png

除却少数核已跑满外, 其他均有很大发挥空间
各核%wa 均占比高, 应该是某一通用设备已达瓶颈 (怀疑IO)

使用iostat查看各设备IO负载

image.png

注意, iostat 显示的是从系统开机到当前执行时刻的统计信息
增加扩展参数, -x 显示更加详细信息、-d 指定间隔采样信息, 如 iostat -x -d 3

选项  说明
rrqm/s  每秒对该设备的读请求被合并次数，文件系统会对读取同块(block)的请求进行合并
wrqm/s  每秒对该设备的写请求被合并次数
r/s 每秒完成的读次数
w/s 每秒完成的写次数
rkB/s   每秒读数据量(kB为单位)
wkB/s   每秒写数据量(kB为单位)
avgrq-sz    平均每次IO操作的数据量(扇区数为单位)
avgqu-sz    平均等待处理的IO请求队列长度
await   平均每次IO请求等待时间(包括等待时间和处理时间，毫秒为单位)
svctm   平均每次IO请求的处理时间(毫秒为单位)
%util   采用周期内用于IO操作的时间比率，即IO队列非空的时间比率

根据间隔采样信息, 可以看出有两个设备%util已经到达IO瓶颈
看起来有极大可能是因为IO瓶颈导致的卡顿

使用pidstat查看系统各进程资源占用情况
因为截图太长就不贴图了, 使用文本记录, 仅保留流速 > 1000KB/s 进程

01:01:53 AM       PID   kB_rd/s   kB_wr/s kB_ccwr/s  Command

# 01:01:53 AM
01:01:53 AM     14603 166121.33 166112.00      0.00  split
...
01:01:53 AM     31865   4850.67    452.00     17.33  mysqld

# 01:01:56 AM
01:01:56 AM     14603  55850.67  55850.67      0.00  split
...
01:01:56 AM     31865   1733.33   1161.33      5.33  mysqld

# 01:01:59 AM
01:01:59 AM     14603  66261.33  66261.33      0.00  split
...
01:01:59 AM     31865   3794.67   1293.33      8.00  mysqld

# 01:02:02 AM
01:02:02 AM     14603  45098.67  45098.67      0.00  split
...
01:02:02 AM     31865   2722.67   1069.33      2.67  mysqld

# 01:02:05 AM
01:02:05 AM     14603  41258.67  41258.67      0.00  split
...
01:02:05 AM     31865   2410.67   1248.00      0.00  mysqld
...
01:02:05 AM     39571      2.67  53760.00  45652.00  php-cgi
01:02:05 AM     39612    166.67      0.00      0.00  python
01:02:05 AM     39686    529.33   1028.00      0.00  php-cgi
01:02:05 AM     39692      0.00  37765.33  27514.67  php-cgi
01:02:05 AM     39766      0.00  39549.33  29500.00  php-cgi

# 01:02:08 AM
01:02:08 AM     14603  25898.67  25898.67      0.00  split
...
01:02:08 AM     31865   4256.00    413.33      9.33  mysqld
...
01:02:08 AM     39910      0.00  42377.33  37212.00  php-cgi
01:02:08 AM     39956     64.00   1049.33      0.00  php-cgi
01:02:08 AM     39964   1118.67   3650.67      0.00  java
01:02:08 AM     40015      0.00  40624.00  32236.00  php-cgi
01:02:08 AM     40531      0.00  33861.33  25893.33  php-cgi

# 01:02:11 AM
01:02:11 AM     14603  52224.00  52224.00      0.00  split
...
01:02:11 AM     31865   5024.00      5.33      5.33  mysqld
...
01:02:11 AM     40636      0.00  44320.00  35228.00  php-cgi

# 01:02:14 AM 
01:02:14 AM     14603  49792.00  49792.00      0.00  split
...
01:02:14 AM     31865   4892.00    105.33     13.33  mysqld
...
01:02:14 AM     40694      0.00  39513.33  34232.00  php-cgi

# 01:02:17 AM
01:02:17 AM     14603  41941.33  41973.33      0.00  split
...
01:02:17 AM     31865   2029.33    373.33      0.00  mysqld

# 01:02:20 AM 
01:02:20 AM     14603  63189.33  63157.33      0.00  split
...
01:02:20 AM     31865   4366.67   1802.67     10.67  mysqld

# 01:02:23 AM
01:02:23 AM     14603  63018.67  63018.67      0.00  split
...
01:02:23 AM     31865   4021.33    657.33     21.33  mysqld
...
01:02:23 AM     39571      2.67  53760.00  45652.00  php-cgi
01:02:23 AM     39612    166.67      0.00      0.00  python
01:02:23 AM     39686    529.33   1028.00      0.00  php-cgi

注意, pidstat 首次显示的是自系统启动开始的各项统计信息
增加扩展参数 -d 指定间隔采样信息, 如pidstat -d 3

PID 进程id
kB_rd/s 每秒从磁盘读取的KB
kB_wr/s 每秒写入磁盘KB
kB_ccwr/s 任务取消的写入磁盘的KB。当任务截断脏的pagecache的时候会发生。
COMMAND task的命令名

根据上面信息可以看出, 卡顿期间有两个进程, 分别为 split(14603) mysqld(31865)

使用ps pwdx根据pid确认任务路径和对应进程

ps -ef | grep [pid] 可唯一定位当前进程名
pwdx [pid] 可唯一定位当前进程启动路径
ll /proc/[pid] 亦可实现

后记, 根据确认进程, 在kill掉进程后, 卡顿问题邹解, %wa、%util占比回落, 卡顿问题解决
高IO任务优化提上日程。