之前遇到过一个mysql线上故障,ubunt20,机器内存使用率99%(机器只有几十兆可用内存),load值100+,几乎所有命令都是卡死状态,最终应用侧停掉所有访问后,系统性能有所缓解,升级机器配置后,暂时解决问题。

一直没有找到load值打到100多的根因,怀疑是内存引起的,尝试复现。

测试环境:2c1G机器 ubuntu20操作系统。利用redis写入数据,把内存打到99%

查看内存剩余情况,只有几十兆的可用空间,现在机器已经卡顿了。

root@ip-172-31-30-45:~# free -m
              total        used        free      shared  buff/cache   available
Mem:            943         855          53           0          34           8
Swap:             0           0           0

通过 top 持续观察,load值一直在往上升,同时有iowait,kswapd0 进程偶尔会把CPU打满。

top - 18:16:36 up 21 days,  7:22,  4 users,  load average: 10.03, 6.14, 5.14
Tasks: 136 total,   5 running, 131 sleeping,   0 stopped,   0 zombie
%Cpu0  :  0.3 us, 86.7 sy,  0.0 ni,  0.0 id, 13.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu1  :  0.0 us, 65.4 sy,  0.0 ni,  0.0 id, 34.6 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :    943.8 total,     53.9 free,    855.4 used,     34.5 buff/cache
MiB Swap:      0.0 total,      0.0 free,      0.0 used.      9.4 avail Mem 

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                                                    
     91 root      20   0       0      0      0 R  64.1   0.0  65:22.01 kswapd0                                                                                    
 122612 root      20   0  873472  15252      0 S  21.4   1.6   0:25.48 snapd                                                                                      
    920 root      20   0 1395760  14320      0 S  10.4   1.5  19:34.52 ssm-agent-worke                                                                            
    448 root      20   0 1308796   7160      0 S   9.5   0.7   7:40.52 amazon-ssm-agen                                                                            
 122724 root      20   0   26352  12144   2232 R   1.5   1.3   0:02.41 python3                                                                                    
    458 root      20   0 1418784  13264      0 S   1.1   1.4  12:40.74 containerd                                                                                 
 122737 root      20   0  758980 652596    476 R   1.1  67.5   0:01.46 redis-server                                                                               
  94147 root       0 -20       0      0      0 R   0.9   0.0   0:13.97 loop3                                                                                      
    297 root       0 -20       0      0      0 D   0.6   0.0   0:32.70 loop6                                                                                      
     13 root      20   0       0      0      0 I   0.2   0.0   0:23.22 rcu_sched                                                                                  
    611 root      20   0   27360  14144   1388 S   0.2   1.5   1:30.46 python                                                                                     
 122482 ubuntu    20   0   13688   2928   1468 S   0.2   0.3   0:01.74 sshd                                                                                       
 122715 root      20   0   11024   2556   1824 R   0.2   0.3   0:01.50 top                                                                                        
      1 root      20   0  168744   6396   2008 S   0.0   0.7   0:56.16 systemd                                                                                    
      2 root      20   0       0      0      0 S   0.0   0.0   0:00.09 kthreadd                                                                                   
      3 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 rcu_gp                                                                                     
      4 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 rcu_par_gp                                                                                 
      6 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 kworker/0:0H-events_highpri                                                                
      9 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 mm_percpu_wq                                                                               
     10 root      20   0       0      0      0 S   0.0   0.0   0:00.00 rcu_tasks_rude_                                                                            
     11 root      20   0       0      0      0 S   0.0   0.0   0:00.00 rcu_tasks_trace                                                                            
     12 root      20   0       0      0      0 S   0.0   0.0   0:02.09 ksoftirqd/0                                                                                
     14 root      rt   0       0      0      0 S   0.0   0.0   0:07.44 migration/0                                                                                
     15 root     -51   0       0      0      0 S   0.0   0.0   0:00.00 idle_inject/0                                                                              
     16 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/0                                                                                    
     17 root      20   0       0      0      0 S   0.0   0.0   0:00.10 cpuhp/1                                                                                    
     18 root     -51   0       0      0      0 S   0.0   0.0   0:00.00 idle_inject/1                                                                              
     19 root      rt   0       0      0      0 S   0.0   0.0   0:05.67 migration/1                                                                                
     20 root      20   0       0      0      0 S   0.0   0.0   0:02.64 ksoftirqd/1                                                                                
     22 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 kworker/1:0H-events_highpri

执行iostat -xd 1 命令,查看磁盘运行情况,发现在大量读情况。

root@ip-172-31-30-45:~#  iostat -xd 1
Device            r/s     rkB/s   rrqm/s  %rrqm r_await rareq-sz     w/s     wkB/s   wrqm/s  %wrqm w_await wareq-sz     d/s     dkB/s   drqm/s  %drqm d_await dareq-sz  aqu-sz  %util
loop0            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop1            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop10           0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop2            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop3           51.23   2404.93     0.00   0.00   21.46    46.94    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    1.10 121.58
loop4            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop5            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop6           50.25   2270.44     0.00   0.00   22.34    45.19    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    1.12 120.79
loop7            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop8            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop9            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
nvme0n1       2808.37 167586.21     0.00   0.00    6.54    59.67    2.46     19.70     2.46  50.00    5.60     8.00    0.00      0.00     0.00   0.00    0.00     0.00   18.38 127.88


Device            r/s     rkB/s   rrqm/s  %rrqm r_await rareq-sz     w/s     wkB/s   wrqm/s  %wrqm w_await wareq-sz     d/s     dkB/s   drqm/s  %drqm d_await dareq-sz  aqu-sz  %util
loop0            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop1            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop10           0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop2            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop3           31.03   1463.55     0.00   0.00   17.14    47.16    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.53  59.51
loop4            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop5            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop6           30.54   1309.36     0.00   0.00   16.73    42.87    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.51  60.30
loop7            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop8            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop9            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
nvme0n1       1546.80  83822.66   204.43  11.67    5.56    54.19    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    8.61  63.84


Device            r/s     rkB/s   rrqm/s  %rrqm r_await rareq-sz     w/s     wkB/s   wrqm/s  %wrqm w_await wareq-sz     d/s     dkB/s   drqm/s  %drqm d_await dareq-sz  aqu-sz  %util
loop0            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop1            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop10           0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop2            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop3           52.00   2334.00     0.00   0.00   20.96    44.88    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    1.09 123.60
loop4            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop5            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop6           47.00   2449.00     0.00   0.00   24.34    52.11    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    1.14 125.60
loop7            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop8            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
loop9            0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00    0.00   0.00
nvme0n1       2930.00 178904.00   842.00  22.32    7.10    61.06    0.00      0.00     0.00   0.00    0.00     0.00    0.00      0.00     0.00   0.00    0.00     0.00   20.81 136.40

使用 iotop 命令想查看有读写的进程,等了半天才出现结果,并没有查看到读写的进程,也可能是太卡了,没有刷新出来。

换个命令,继续看。 pidstat -d 1 查看有读写的进程,发现系统的一些命令和redis都开始有磁盘读情况,这个很诡异。在系统没有负载的情况,很少有线程产生磁盘读,即使产生,也只是少量磁盘读,感觉还和内存有关系。

root@ip-172-31-30-45:/usr/local/redis-5.0.13#     pidstat -d 1 
Linux 5.11.0-1022-aws (ip-172-31-30-45)         03/18/22        _x86_64_        (2 CPU)

18:18:58      UID       PID   kB_rd/s   kB_wr/s kB_ccwr/s iodelay  Command
18:18:59        0         1  12866.09      0.00      0.00     103  systemd
18:18:59        0       165  12688.70     20.87      0.00     107  systemd-journal
18:18:59        0       297   6313.04      0.00      0.00      96  loop6
18:18:59        0       448    622.61      0.00      0.00       0  amazon-ssm-agen
18:18:59        0       458  27926.96      0.00      0.00       0  containerd
18:18:59        0       611  11808.70      0.00      0.00     103  python
18:18:59        0       920   1088.70      0.00      0.00       0  ssm-agent-worke
18:18:59        0     94147   7373.91      0.00      0.00      90  loop3
18:18:59     1000    122482  12845.22      0.00      0.00     105  sshd
18:18:59        0    122612   1913.04      0.00      0.00      27  snapd
18:18:59        0    122715  10751.30      0.00      0.00     104  top
18:18:59        0    122737  13947.83      0.00      0.00     105  redis-server
18:18:59        0    122762  13947.83      0.00      0.00     108  iotop
18:18:59        0    122763    737.39      0.00      0.00      13  pidstat

继续分析内存,sar -B 1 查看结果很不正常,网上参考了一些资料,内存一直在换出内存页。

root@ip-172-31-30-45:/usr/local/redis-5.0.13# sar -B 1
Linux 5.11.0-1022-aws (ip-172-31-30-45)         03/18/22        _x86_64_        (2 CPU)

18:20:10     pgpgin/s pgpgout/s   fault/s  majflt/s  pgfree/s pgscank/s pgscand/s pgsteal/s    %vmeff
18:20:11    129587.85     11.21   2624.30   1079.44  33643.93 1253757.01      0.00  65388.79      5.22
18:20:12    133341.05     12.63   2749.47   1143.16  34433.68 1336996.84      0.00  67088.42      5.02
18:20:13    128673.53     11.76   2417.65   1061.76  33025.49 1280571.57      0.00  64507.84      5.04
18:20:14    141319.80     11.88   2768.32   1213.86  36835.64 1448100.00      0.00  72093.07      4.98
18:20:15    137649.06     22.64   2596.23   1129.25  35185.85 1356853.77      0.00  68616.98      5.06
18:20:16    135702.08      0.00   2590.62   1131.25  35068.75 1300878.12      0.00  68475.00      5.26
18:20:17    138187.74      7.55   2639.62   1166.98  35675.47 1432819.81      0.00  69777.36      4.87
18:20:18    127922.22     12.12   2411.11   1064.65  33176.77 1290246.46      0.00  64759.60      5.02
18:20:19    135751.52     12.12   2569.70   1141.41  35144.44 1247659.60      0.00  68553.54      5.49
18:20:20    131892.23     11.65   2494.17   1077.67  34009.71 1267085.44      0.00  66330.10      5.23
18:20:21    136640.20     11.76   2585.29   1127.45  34988.24 1437513.73      0.00  68400.00      4.76
18:20:22    134836.54     92.31   2616.35   1140.38  34822.12 1475377.88      0.00  68105.77      4.62
18:20:23    122284.54      0.00   2323.71   1011.34  31298.97 1391742.27      0.00  61344.33      4.41
18:20:25    144998.10     38.10   2726.67   1200.00  37841.90 1619358.10      0.00  74034.29      4.57
18:20:25    133615.15     12.12   2518.18   1100.00  34266.67 1452670.71      0.00  67173.74      4.62
18:20:27    131804.95      7.92   2507.92   1106.93  34002.97 1384208.91      0.00  66491.09      4.80
18:20:28    133263.73     23.53   2604.90   1142.16  34750.00 1455180.39      0.00  67962.75      4.67
18:20:29    136841.58     11.88   2552.48   1132.67  34965.35 1444651.49      0.00  68576.24      4.75
18:20:30    136734.65     19.80   2629.70   1159.41  35301.98 1537196.04      0.00  69091.09      4.49
18:20:31    131172.55      0.00   2572.55   1114.71  33513.73 1539543.14      0.00  65627.45      4.26
18:20:32    133487.13     27.72   2747.52   1143.56  34372.28 1470575.25      0.00  67312.87      4.58
18:20:33    133665.05     11.65   2673.79   1146.60  34334.95 1540199.03      0.00  67248.54      4.37
18:20:34    126963.64      8.08   2451.52   1067.68  32934.34 1402451.52      0.00  64511.11      4.60
18:20:35    136550.98     23.53   2670.59   1143.14  35300.98 1473324.51      0.00  68982.35      4.68

总结:从sar -B 结果及网上参考的资料看,在内存紧张时,程序并没有把有代码加载到内存中,当需要执行的代码不在内存中时,需要生新读取磁盘加载到内存中,才会有大量的磁盘读出现,以及IO WAIT升高,LOAD值升高估计也是这个问题,许多程序都需要从磁盘中读取代码并加载到内存中。
不过都是个人怀疑,没有一个完全成立的证据。
另外 ubuntu 在内OOM机制上和centos 上差距挺大的,本想在centos7 上复现这个场景,结果centos7 上当内存剩作不多时,瞬间就把redis 进程OOM掉了,不会有卡住的情况。
在ubuntu系统上,系统宁可一直卡住,也不OOM掉内存最大的程序,但也不是不会oom,如果我在已经出现卡顿的场景下,继续往redis写数据,卡10-20分钟最终还是会触发OOM。

参考:
https://www.jianshu.com/p/ea7ed85918achttps://www.jianshu.com/p/f9b8c139c2edhttps://www.its404.com/article/wangquan1992/105036282https://www.learnsteps.com/difference-between-minor-page-faults-vs-major-page-faults/


python-redis脚本

import redis
a='a'*1000000

r=redis.Redis(host='127.0.0.1',port=6379,decode_responses=True)
for x in range(10):
    r.lpush('liliil',a)