记一次服务器高负载低CPU使用率问题的排查

SherLock_OD
1,414 阅读3分钟

问题现象

某时间点监控报警 10.0.0.1 的cpu负载升高，但是没找到cpu使用率明显比较高的进程。

问题排查

  1. 查看cpu使用率
$ top -c
top - 10:37:06 up 622 days, 18:13,  1 user,  load average: 55.14, 55.25, 55.94
Tasks: 247 total,   1 running, 246 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.3 us,  0.5 sy,  0.0 ni, 99.1 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem : 32948128 total,  2140896 free, 10739188 used, 20068044 buff/cache
KiB Swap: 16777212 total, 16598708 free,   178504 used. 20294412 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
17549 root      20   0 13.868g 3.532g  13812 S   1.3 11.2   4386:22 /usr/java/jdk1.8.0_121/bin/java -Djava.util.logging.config.file=/data/ifengsite/java/tomcat/conf/logging.properties -Djava.util.logging.manage+
 1261 root      20   0  560244   5436   4924 S   0.3  0.0 138:35.97 /usr/bin/python -Es /usr/sbin/tuned -l -P
17443 root      20   0       0      0      0 S   0.3  0.0   0:12.28 [kworker/1:1]
22211 root      20   0  146324   2292   1504 R   0.3  0.0   0:01.83 top -c
    1 root      20   0   41536   3252   2076 S   0.0  0.0  65:07.05 /usr/lib/systemd/systemd --switched-root --system --deserialize 21
    2 root      20   0       0      0      0 S   0.0  0.0   0:22.00 [kthreadd]
    3 root      20   0       0      0      0 S   0.0  0.0  30:23.26 [ksoftirqd/0]
    5 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 [kworker/0:0H]
    7 root      rt   0       0      0      0 S   0.0  0.0   0:56.78 [migration/0]

可以看出，服务器负载很高，但没有看到明显高cpu使用率的进程。

  1. 查看某进程的子进程cpu使用率情况
$ top -Hp <pid>
top - 10:24:24 up 622 days, 18:01,  1 user,  load average: 55.05, 55.65, 56.88
Threads: 176 total,   0 running, 176 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.5 us,  0.7 sy,  0.0 ni, 98.8 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem : 32948128 total,  2124500 free, 10737712 used, 20085916 buff/cache
KiB Swap: 16777212 total, 16598708 free,   178504 used. 20295740 avail Mem
PID to signal/kill [default pid = 17549]
  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND
17549 root      20   0 13.868g 3.531g  13812 S  0.0 11.2   0:00.00 java
17550 root      20   0 13.868g 3.531g  13812 S  0.0 11.2   0:01.05 java
17551 root      20   0 13.868g 3.531g  13812 S  0.0 11.2  32:20.15 java
17552 root      20   0 13.868g 3.531g  13812 S  0.0 11.2  32:20.45 java
17553 root      20   0 13.868g 3.531g  13812 S  0.0 11.2  32:22.92 java
17554 root      20   0 13.868g 3.531g  13812 S  0.0 11.2  32:21.64 java
17555 root      20   0 13.868g 3.531g  13812 S  0.0 11.2  32:20.46 java
17556 root      20   0 13.868g 3.531g  13812 S  0.0 11.2  32:20.89 java
17557 root      20   0 13.868g 3.531g  13812 S  0.0 11.2  32:19.77 java
17558 root      20   0 13.868g 3.531g  13812 S  0.0 11.2  32:20.22 java
17559 root      20   0 13.868g 3.531g  13812 S  0.0 11.2  75:17.56 java
17560 root      20   0 13.868g 3.531g  13812 S  0.0 11.2   0:58.44 java
17561 root      20   0 13.868g 3.531g  13812 S  0.0 11.2   1:17.08 java
17562 root      20   0 13.868g 3.531g  13812 S  0.0 11.2   0:00.00 java
17563 root      20   0 13.868g 3.531g  13812 S  0.0 11.2   3:16.71 java
17564 root      20   0 13.868g 3.531g  13812 S  0.0 11.2   3:27.37 java
17565 root      20   0 13.868g 3.531g  13812 S  0.0 11.2   3:40.50 java
17566 root      20   0 13.868g 3.531g  13812 S  0.0 11.2   1:52.72 java
17567 root      20   0 13.868g 3.531g  13812 S  0.0 11.2   0:00.00 java
17568 root      20   0 13.868g 3.531g  13812 S  0.0 11.2  50:56.66 java
  1. 查看磁盘I/O写入情况 iostat
$ iostat
Linux 3.10.0-327.el7.x86_64 (cmpp_tomcatweb_pmop195v137_taiji) 	07/05/2021 	_x86_64_	(8 CPU)

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           3.92    0.00    0.83    0.04    0.00   95.22

Device:            tps    kB_read/s    kB_wrtn/s    kB_read    kB_wrtn
fd0               0.00         0.00         0.00      59780          0
sda               5.70         0.17      1153.12    8907374 62047106018

磁盘I/O情况也没看出异常，至此卡住了，没有思路

  1. 网上搜索"高负载低CPU使用率"的相关问题，获得了一点思路
  • cpu负载值 = running 状态 + interruptible 状态的进程个数之和
  • 也就是说，如果负载值超过cpu核数，那表示出现了以下两种情况：
    • 等待分配cpu资源的进程多了
    • 等待磁盘I/O完成的进程多了
  • 而导致等待磁盘I/O完成的进程过多的原因，又可能有如下几种情况
    1. 磁盘读写请多，导致大量I/O等待：前面通过 iostat 查看没有发现。
    2. MySQL存在没有索引的语句或存在死锁：服务器上个没有MySQL，而且通过前面查看，I/O请求量很少。
    3. 外接硬盘故障，常见如挂载NFS，但是NFS server 故障：这个问题会导致，大量请求无法获取到资源，从而interruptible 状态进程增多，负载增大
  1. 查看挂载情况是否有nfs
$ df -h
hang住了...

这个现象说明磁盘挂载确实有什么问题

  1. 通过mount命令查看
$ mount
...
torage.staff.dev.com:/media on /mnt/source2 type nfs (rw,relatime,vers=3,rsize=65536,wsize=65536,namlen=255,hard,proto=tcp,timeo=600,retrans=2,sec=null,mountaddr=10.0.0.202,mountvers=3,mountport=635,mountproto=udp,local_lock=none,addr=10.0.0.202)
10.0.0.161:/data1/media on /mnt/source3 type nfs (rw,noatime,nodiratime,vers=3,rsize=1048576,wsize=1048576,namlen=255,hard,proto=tcp,timeo=600,retrans=2,sec=sys,mountaddr=10.0.0.161,mountvers=3,mountport=33724,mountproto=udp,local_lock=none,addr=10.0.0.161)
10.0.0.153:/data1/media on /mnt/source4 type nfs (rw,noatime,nodiratime,vers=3,rsize=1048576,wsize=1048576,namlen=255,hard,proto=tcp,timeo=600,retrans=2,sec=sys,mountaddr=10.80.81.153,mountvers=3,mountport=59983,mountproto=udp,local_lock=none,addr=10.0.0.153)
10.0.0.146:/data/media on /mnt/source type nfs (rw,noatime,nodiratime,vers=3,rsize=1048576,wsize=1048576,namlen=255,hard,proto=tcp,timeo=600,retrans=2,sec=sys,mountaddr=10.90.84.146,mountvers=3,mountport=36556,mountproto=udp,local_lock=none,addr=10.0.0.146)
...

通过查看发现，确实挂载了4个NFS网盘，下面检查下server情况。

  1. 检查各nfs网盘情况
$ showmount -e 10.0.0.202
Export list for 10.0.0.202:
/media *

$ showmount -e 10.0.0.161
Export list for 10.0.0.161:
/data1/media *

$ showmount -e 10.0.0.153
Export list for 10.0.0.153:
/data/media *

$ showmount -e 10.0.0.146
^C

可以看到 10.0.0.146 的nfs有故障，端口不通了，我尝试卸载掉，让负载先降下来。

  1. 卸载NFS网盘
$ umount -f /mnt/source
...
umount.nfs: /mnt/source: device is busy

umount 强行卸载也不能成功，应该是还有访问nfs的进程导致的。

  1. 通过fuser命令杀掉访问nfs的进程
# 先查看下都哪些进程再访问，结果一样是hang住。
$ fuser -m -v /mnt/source
^C

# 直接执行kill，同样还是hang住。
$ fuser -k -v /mnt/source

# 在网上看，这时应该可以umount了，就尝试了一下，果然可以，不明白为什么。
$ umount -f /mnt/source
  1. 查看磁盘挂载和cpu负载情况
$ df -h
Filesystem                          Size  Used Avail Use% Mounted on
/dev/sda6                            10G   71M   10G   1% /
devtmpfs                             16G     0   16G   0% /dev
tmpfs                                16G     0   16G   0% /dev/shm
tmpfs                                16G  1.6G   15G  10% /run
tmpfs                                16G     0   16G   0% /sys/fs/cgroup
/dev/sda2                            20G  3.2G   17G  16% /usr
/dev/sda8                            10G   33M   10G   1% /tmp
/dev/sda7                            10G   33M   10G   1% /home
/dev/sda9                           938G  411G  527G  44% /data
/dev/sda1                           497M  108M  390M  22% /boot
/dev/sda3                            20G  537M   20G   3% /var
storage.staff.dev.com:/media   45T   13T   33T  29% /mnt/source2
10.0.0.161:/data1/media            23T 1013G   22T   5% /mnt/source3
tmpfs                               3.2G     0  3.2G   0% /run/user/1004
tmpfs                               3.2G     0  3.2G   0% /run/user/1005
tmpfs                               3.2G     0  3.2G   0% /run/user/10005
10.0.0.153:/data/media             11T 1007G  9.5T  10% /mnt/source4

$ uptime
1:07:11 up 622 days, 18:44,  2 users,  load average: 5.54, 33.51, 47.06

df -h命令恢复，并且cpu负载也降低到正常范围了。

问题总结

  1. 故障的nfs是由于同事调整 Server 端 IP 地址导致的，调整前漏掉了这台client。
  2. 服务器监控不到位，没有配置nfs相关的报警。
  3. Linux 底层知识不熟悉，之前没搞清楚cpu负载值的真正含义代表什么。
avatar
文章
阅读
粉丝