容器因内存频繁OOM而引发的内核“血案”
腾讯云线上一个大客户上云过程中遇到在TKE环境中，出现node节点频繁夯死的现象，经过团队深入分析得知是触发了在ext4文件系统上内存频繁OOM而引发内核hung死，本文抱着学习vmcore的心态对该内核bug的原因做深入分析，如何复现，如何规避，以及在kubernetes容器环境下内核如何选型的最佳实践。
1. 勘查现场
客户上云过程中将原有在数据中心自建kubernetes集群迁移至腾讯云TKE集群，迁移过程中发现其中有一个容器沙箱环境频繁出现node节点夯死现象，目前已经出现5-6次，亟需定位原因。出现异常时节点无法登陆且需要手动重启才能恢复，"罪犯"逃离，异常后节点状态置为NotReady，无状态化pods会自动驱逐至其他节点，有状态化StatefullSets部署的pods无法驱逐成功。
出现异常时通过巴拉多观察监控，可以发现一个共同的现象：异常期间容器所在的cbs数据盘读IO瞬间打满，磁盘util利用率持续达到100%
前两次出现异常时候客户直接重启机器恢复，“案发现场”已逃离，无法获知到异常时的蛛丝马迹。为了抓取案发现场，等待第三次复现，联系CVM计算专项同学手动触发“魔法键”生成vmcore。
2. 浮出水面
2.1 尝试破案
由于事先知道机器已夯死，调查组通过SysRq手动触发生成vmcore文件，安装crash和kernel-debuginfo工具包，调查组开始犯罪现场的调研工作：尝试分析coredump文件，先看下D进程的情况，可以看到有17w个进程，其中有2081个进程处于僵死状态，大部分是Java进程。
crash> sys
KERNEL: /usr/lib/debug/lib/modules/3.10.0-1127.19.1.el7.x86\\_64/vmlinux
DUMPFILE: vmcore [PARTIAL DUMP]
CPUS: 64
DATE: Mon Aug 30 10:46:05 2021
UPTIME: 53 days, 20:45:42
LOAD AVERAGE: 2142.96, 2141.13, 2126.04
TASKS: 17585
NODENAME: VM-8-17-centos
RELEASE: 3.10.0-1127.19.1.el7.x86\\_64
VERSION: #1 SMP Tue Aug 25 17:23:54 UTC 2020
MACHINE: x86\\_64 (2595 Mhz)
MEMORY: 128 GB
PANIC: "SysRq : Trigger a crash" //通过SysRq手动触发生成crash
crash> ps | wc -l //一共有17586个进程
17586
crash> ps | grep UN | wc -l //其中2081个进程处于僵死状态
2081
crash> ps | grep UN //大部分僵死进程是Java进程，除此之外还有docker等进程
1459 2 24 ffff94d2fd95d230 UN 0.0 0 0 [jbd2/vdb-8]
4441 4192192 11 ffff94c9c7fa62a0 UN 0.5 36955132 679404 java
4444 4192192 12 ffff94c8a09941c0 UN 0.5 36955132 679404 java
4585 4192192 48 ffff94c8a09920e0 UN 0.5 36955132 679404 java
4586 4192192 14 ffff94c8a0993150 UN 0.5 36955132 679404 java有这么多进程处于僵死状态，到底是什么进程导致系统hung死呢？先统计下所有hung住的进程都hung在哪里
crash> foreach UN bt | awk '/#2/ {print $3,$5}' |sort|uniq -c|sort -n
1725 rwsem\\_down\\_read\\_failed ffffffffb3187795
160 schedule\\_timeout ffffffffb31838b1
119 wait\\_transaction\\_locked ffffffffc04f8085
52 \\_\\_mutex\\_lock\\_slowpath ffffffffb3184c57
22 rwsem\\_down\\_write\\_failed ffffffffb31874e5
1 trace\\_do\\_page\\_fault ffffffffb318da26
1 \\_\\_mutex\\_lock\\_killable\\_slowpath ffffffffb318450c
1 jbd2\\_log\\_wait\\_commit ffffffffc0501875
1 jbd2\\_journal\\_commit\\_transaction ffffffffc04fb30c
1 handle\\_mm\\_fault ffffffffb2bf5d80
1 \\_\\_do\\_page\\_fault ffffffffb318d653
1 do\\_async\\_page\\_fault ffffffffb318cfa2
1 async\\page\\_fault ffffffffb31897a8可以看到有1725个进程在等待rwsem，推测进程卡住是因为rwsem本身卡住或者是其他原因卡住而导致，查看最早卡死的进程，可以看到有jbd2/vdb-8进程出现了僵死，查看log日志可以看到磁盘出现了"jbd2/vdb-8:1459 blocked for more than 120 seconds.",还有polkitd，kubelet等进程
crash> ps |grep UN | head //jbd2/vdb进程出现卡死
1459 2 24 ffff94d2fd95d230 UN 0.0 0 0 [jbd2/vdb-8]
1534 1 52 ffff94d2e6f520e0 UN 0.0 614460 7176 polkitd
1582 1 0 ffff94d2e6f55230 UN 0.0 65444 5528 dbus-daemon
1607 1 42 ffff94d2faaed230 UN 0.1 4580440 160912 kubelet
crash> log
[4453228.128056] INFO: task jbd2/vdb-8:1459 blocked for more than 120 seconds. //vdb磁盘出现了卡死
[4453228.129706] "echo 0 > /proc/sys/kernel/hung\\_task\\_timeout\\_secs" disables this message.
[4453228.131078] jbd2/vdb-8 D ffff94d2fd95d230 0 1459 2 0x00000000
[4453228.128056] INFO: task jbd2/vdb-8:1459 blocked for more than 120 seconds. //vdb出现卡死，超过120s后即卡死
[4453228.129706] "echo 0 > /proc/sys/kernel/hung\\_task\\_timeout\\_secs" disables this message.
[4453228.131078] jbd2/vdb-8 D ffff94d2fd95d230 0 1459 2 0x00000000
[4453228.131082] Call Trace:
[4453228.131807] [<ffffffffb2ad3820>] ? task\\_rq\\_unlock+0x20/0x20
[4453228.132907] [<ffffffffb3185da9>] schedule+0x29/0x70
[4453228.133942] [<ffffffffc04fb30c>] jbd2\\_journal\\_commit\\_transaction+0x23c/0x19c0 [jbd2]
[4453228.135309] [<ffffffffb2ae1bfe>] ? account\\_entity\\_dequeue+0xae/0xd0
[4453228.136500] [<ffffffffb2ae539c>] ? dequeue\\_entity+0x11c/0x5c0
[4453228.137614] [<ffffffffb2a6d3be>] ? kvm\\_sched\\_clock\\_read+0x1e/0x30
[4453228.138752] [<ffffffffb2ae69a1>] ? put\\_prev\\_entity+0x31/0x400
[4453228.139849] [<ffffffffb2a2b59e>] ? \\_\\_switch\\_to+0xce/0x580
[4453228.140883] [<ffffffffb2ad53fe>] ? finish\\_task\\_switch+0x4e/0x1c0
[4453228.141993] [<ffffffffb2ac7780>] ? wake\\_up\\_atomic\\_t+0x30/0x30
[4453228.143063] [<ffffffffb3185942>] ? \\_\\_schedule+0x402/0x840
[4453228.144107] [<ffffffffb2aae97e>] ? try\\_to\\_del\\_timer\\_sync+0x5e/0x90
[4453228.145239] [<ffffffffc0501f39>] kjournald2+0xc9/0x260 [jbd2]
[4453228.146337] [<ffffffffb2ac7780>] ? wake\\_up\\_atomic\\_t+0x30/0x30
[4453228.147429] [<ffffffffc0501e70>] ? commit\\_timeout+0x10/0x10 [jbd2]
[4453228.148563] [<ffffffffb2ac6691>] kthread+0xd1/0xe0
[4453228.149531] [<ffffffffb2ac65c0>] ? insert\\_kthread\\_work+0x40/0x40
[4453228.150704] [<ffffffffb3192d24>] ret\\_from\\_fork\\_nospec\\_begin+0xe/0x21
[4453228.151948] [<ffffffffb2ac65c0>] ? insert\\_kthread\\_work+0x40/0x40通过这里可以知道vdb的jbd2已经出现了卡死，是vdb卡死导致内核奔溃还是rwsem进程导致vdb奔溃呢？ 为什么jbd2会出现卡死呢？
什么是ext4/jbd2 ,参考 Linux: The Journaling Block Device（https://web.archive.org/web/20070926223043/http://kerneltrap.org/node/6741），ext4 文件系统基于 jbd2 以 WAL（write-ahead logging）形式更新元数据，防止系统 crash 时发生元数据损坏。每一个 ext4 文件系统实例对应一个 jbd2 Journal 实例。每个用户线程的一次数据更新称为一个 Handle，在时间上连续的多个 Handle（可能来自不同线程）组成一个 Transaction，以便实现批量提交。Transaction 提交满足原子性。
查看下jbd2进程的堆栈信息，可以看到jbd2/vdb-8在等待jbd2_journal_commit_transaction
crash> ps |grep vdb
1459 2 24 ffff94d2fd95d230 UN 0.0 0 0 [jbd2/vdb-8]
crash> bt 1459 //查看jbd2/vdb-8的堆栈信息
PID: 1459 TASK: ffff94d2fd95d230 CPU: 24 COMMAND: "jbd2/vdb-8"
#0 [ffff94d2fb68bc08] \\_\\_schedule at ffffffffb31858fa
#1 [ffff94d2fb68bc98] schedule at ffffffffb3185da9
#2 [ffff94d2fb68bca8] jbd2\\_journal\\_commit\\_transaction at ffffffffc04fb30c [jbd2]
#3 [ffff94d2fb68be48] kjournald2 at ffffffffc0501f39 [jbd2]
#4 [ffff94d2fb68bec8] kthread at ffffffffb2ac6691
#5 [ffff94d2fb68bf50] ret\\_from\\_fork\\_nospec\\_begin at ffffffffb3192d24 排行前面的进程卡死是什么导致的呢，通过查看polkitd进程和后面的kubelet进程，其堆栈信息均相同，因此怀疑是相同的原因导致后面的进程卡死，也就是说后面的进程是受害者，因为vdb卡死而导致进程陆续卡死
crash> bt 1534
PID: 1534 TASK: ffff94d2e6f520e0 CPU: 52 COMMAND: "polkitd"
#0 [ffff94d2ee8ab9e8] \\_\\_schedule at ffffffffb31858fa
#1 [ffff94d2ee8aba78] schedule at ffffffffb3185da9
#2 [ffff94d2ee8aba88] schedule\\_timeout at ffffffffb31838b1
#3 [ffff94d2ee8abb30] io\\_schedule\\_timeout at ffffffffb318549d
#4 [ffff94d2ee8abb60] io\\_schedule at ffffffffb3185538
#5 [ffff94d2ee8abb70] bit\\_wait\\_io at ffffffffb3183f01
#6 [ffff94d2ee8abb88] \\_\\_wait\\_on\\_bit at ffffffffb3183a27
#7 [ffff94d2ee8abbc8] wait\\_on\\_page\\_bit\\_killable at ffffffffb2bc0c93
#8 [ffff94d2ee8abc20] \\_\\_lock\\_page\\_or\\_retry at ffffffffb2bc0d62
#9 [ffff94d2ee8abc40] filemap\\_fault at ffffffffb2bc1157 //
#10 [ffff94d2ee8abcb0] ext4\\_filemap\\_fault at ffffffffc0651706 [ext4]
#11 [ffff94d2ee8abcd8] \\_\\_do\\_fault at ffffffffb2bedf6a
#12 [ffff94d2ee8abd58] do\\_read\\_fault at ffffffffb2bee51c
#13 [ffff94d2ee8abdb8] handle\\_mm\\_fault at ffffffffb2bf5d80
#14 [ffff94d2ee8abe80] \\_\\_do\\_page\\_fault at ffffffffb318d653
#15 [ffff94d2ee8abef0] trace\\_do\\_page\\_fault at ffffffffb318da26
#16 [ffff94d2ee8abf30] do\\_async\\_page\\_fault at ffffffffb318cfa2
#17 [ffff94d2ee8abf50] async\\_page\\_fault at ffffffffb31897a8
RIP: 00007f3604c3da9f RSP: 00007ffd161cf660 RFLAGS: 00010207
RAX: 0000000000000001 RBX: 0000000000000001 RCX: ffffffffffffffff
RDX: 0000000000000001 RSI: 0000000000000081 RDI: 00007f3604e79658
RBP: 0000558426397850 R8: 0000000000000000 R9: 000055842638bf60
R10: 0000000000000000 R11: 0000000000000246 R12: 0000558426397858
R13: 0000558426397860 R14: 00007f35f000f410 R15: 00007f3604c27940
ORIG\\_RAX: ffffffffffffffff CS: 0033 SS: 002b至此，推测是vdb/jbd2卡死导致此次机器hung死的原因，而vdb卡死原因从监控上来看是读IO瞬间突增导致cbs云盘被打满。
至于磁盘读IO的来源，和客户了解业务模型中并为有读IO瞬间突增的请求，其容器只有常规的写日志操作，由于node节点并为部属atop或者iotop监控，无法抓取到磁盘IO突增时刻IO所属的进程，因此无法获知vdb卡死的来由。
经过评估，需要在node节点上部署atop和iotop监控，待复现抓取异常IO的来源，通过crontab部署iotop监控，其中iotop以每秒的粒度获取监控信息，通过crontab每天运行一次，内容如下:
01 10 \\* \\* \\* nohup /usr/sbin/iotop -botq --iter=86400 >> /data1/iotop/$(date "+\\%Y\\%m\\%d")\\_iotop.log部署完监控后，待“犯罪分子”再次光临。
2.2 陷入两难
经过两周的时间等待，犯罪分子于8月30日02:57分再次作案，警方希望通过已部署的“抓捕工具”（atop和iotop）能够抓到犯罪证据（磁盘读高IO来源）
然而，通过分析atop和iotop发现，犯罪分子相当“狡猾”，案发之后所有的监控都失效了：iotop在02:57分后就无日志记录； atop最后一次日志时间为02:48:37 （10分钟采集一次）
https://km.woa.com/files/photos/pictures/202109/1631437802_47_w971_h261.png
到2:57分之后系统就处于夯死状态，此时调查组陷入了进退两难的界面：怀疑内核hung死是由于磁盘读高IO导致，内核夯死导致监控无法抓到现场，犯罪分子逃之夭夭，此时陷入两难界面：到底是内核问题引起 or 磁盘高IO导致机器夯死？如若无法找到真凶，找出幕后罪魁祸首，客户切量上云将会受到极大的阻碍，调查组增派专家支援，试图从残留的犯罪现场中寻找蛛丝马迹。
2.3 拨开云雾
首先分析下为何atop和iotop监控无法采集到犯罪现场：通过查看atop和iotop的堆栈信息，可以看到：iotop和atop因获取rwsem量而卡住，导致卡死无法获取到当时的监控信息
crash> ps | grep iotop
607982 607971 15 ffff94cc443b20e0 UN 0.1 275244 86412 iotop
crash> bt 607982 //iotop因获取rwsem而卡住
PID: 607982 TASK: ffff94cc443b20e0 CPU: 15 COMMAND: "iotop"
#0 [ffff94c7ec177cb8] \\_\\_schedule at ffffffffb31858fa
#1 [ffff94c7ec177d40] schedule at ffffffffb3185da9
#2 [ffff94c7ec177d50] rwsem\\_down\\_read\\_failed at ffffffffb3187795 #卡住
#3 [ffff94c7ec177dd8] call\\_rwsem\\_down\\_read\\_failed at ffffffffb2d96748
#4 [ffff94c7ec177e28] down\\_read at ffffffffb31850b0
#5 [ffff94c7ec177e40] proc\\_pid\\_cmdline\\_read at ffffffffb2cc9b32
#6 [ffff94c7ec177ed8] vfs\\_read at ffffffffb2c4d06f
#7 [ffff94c7ec177f08] sys\\_read at ffffffffb2c4dedf
#8 [ffff94c7ec177f50] tracesys at ffffffffb3193166 (via system\\_call)
RIP: 00007ff51452d9a0 RSP: 00007ffc4fac8f78 RFLAGS: 00000246
RAX: ffffffffffffffda RBX: 0000000002fc5570 RCX: ffffffffffffffff
RDX: 0000000000001000 RSI: 0000000001cde844 RDI: 0000000000000006
RBP: 00007ff514802380 R8: ffffffffffffffff R9: 0000000000000000
R10: 0000000000000022 R11: 0000000000000246 R12: 0000000000001000
R13: 0000000000000d70 R14: 00007ff514801838 R15: 0000000001cde844
ORIG\\_RAX: 0000000000000000 CS: 0033 SS: 002b
crash> ps |grep atop
867919 1 13 ffff94c9e4e262a0 UN 0.1 142892 125964 atop
crash> bt 867919 //atop因为获取rwsem而卡住，同iotop一致
PID: 867919 TASK: ffff94c9e4e262a0 CPU: 13 COMMAND: "atop"
#0 [ffff94ca23467cb8] \\_\\_schedule at ffffffffb31858fa
#1 [ffff94ca23467d40] schedule at ffffffffb3185da9
#2 [ffff94ca23467d50] rwsem\\_down\\_read\\_failed at ffffffffb3187795
#3 [ffff94ca23467dd8] call\\_rwsem\\_down\\_read\\_failed at ffffffffb2d96748
#4 [ffff94ca23467e28] down\\_read at ffffffffb31850b0
#5 [ffff94ca23467e40] proc\\_pid\\_cmdline\\_read at ffffffffb2cc9b32
#6 [ffff94ca23467ed8] vfs\\_read at ffffffffb2c4d06f
#7 [ffff94ca23467f08] sys\\_read at ffffffffb2c4dedf
#8 [ffff94ca23467f50] tracesys at ffffffffb3193166 (via system\\_call)
RIP: 00007f22cccd69a0 RSP: 00007ffedbfb2d58 RFLAGS: 00000246
RAX: ffffffffffffffda RBX: 000000000214f010 RCX: ffffffffffffffff
RDX: 0000000000000400 RSI: 00007f22cdd56000 RDI: 0000000000000007
RBP: 00007f22ccfab380 R8: ffffffffffffffff R9: 0000000000000000
R10: 0000000000000022 R11: 0000000000000246 R12: 00007f22ccfaa838
R13: 00007f22ccfaa838 R14: 0000000000000d70 R15: 00007f22ccfab5a8
ORIG\\_RAX: 0000000000000000 CS: 0033 SS: 002b为什么会rwsem获取不到信号量呢？通过堆栈和反汇编，找到堆栈的值（获取方法比较复杂）
crash> bt 607982
PID: 607982 TASK: ffff94cc443b20e0 CPU: 15 COMMAND: "iotop"
#0 [ffff94c7ec177cb8] \\_\\_schedule at ffffffffb31858fa
#1 [ffff94c7ec177d40] schedule at ffffffffb3185da9
#2 [ffff94c7ec177d50] rwsem\\_down\\_read\\_failed at ffffffffb3187795
#3 [ffff94c7ec177dd8] call\\_rwsem\\_down\\_read\\_failed at ffffffffb2d96748
#4 [ffff94c7ec177e28] down\\_read at ffffffffb31850b0
#5 [ffff94c7ec177e40] proc\\_pid\\_cmdline\\_read at ffffffffb2cc9b32
#6 [ffff94c7ec177ed8] vfs\\_read at ffffffffb2c4d06f
#7 [ffff94c7ec177f08] sys\\_read at ffffffffb2c4dedf
#8 [ffff94c7ec177f50] tracesys at ffffffffb3193166 (via system\\_call)
RIP: 00007ff51452d9a0 RSP: 00007ffc4fac8f78 RFLAGS: 00000246
RAX: ffffffffffffffda RBX: 0000000002fc5570 RCX: ffffffffffffffff
RDX: 0000000000001000 RSI: 0000000001cde844 RDI: 0000000000000006
RBP: 00007ff514802380 R8: ffffffffffffffff R9: 0000000000000000
R10: 0000000000000022 R11: 0000000000000246 R12: 0000000000001000
R13: 0000000000000d70 R14: 00007ff514801838 R15: 0000000001cde844
ORIG\\_RAX: 0000000000000000 CS: 0033 SS: 002b
crash>
crash> whatis down\\_read
void down\\_read(struct rw\\_semaphore \\*);
crash>
crash> rd ffff94c7ec177dd8 -e ffff94c7ec177e28
ffff94c7ec177dd8: ffffffffb2d96748 0000000000000000 Hg..............
ffff94c7ec177de8: 0000000000000246 00000000000050ad F........P......
ffff94c7ec177df8: ffffe885c50fed40 ffffffffb348d58f @.........H.....
ffff94c7ec177e08: ffff94c7ec177fd8 0000000000000000 ................
ffff94c7ec177e18: ffff94c362f225f8 ffff94c7ec177e38 .%.b....8~......//ffff94c362f225f值
crash>
crash> struct rw\\_semaphore ffff94c362f225f8
struct rw\\_semaphore {
{
count = {
counter = -4294967295
},
\\_\\_UNIQUE\\_ID\\_rh\\_kabi\\_hide1 = {
count = -4294967295
},
{<No data fields>}
},
wait\\_lock = {
raw\\_lock = {
val = {
counter = 0
}
}
},
osq = {
tail = {
counter = 0
}
},
wait\\_list = {
next = 0xffff94cd30223d90
},
owner = 0xffff94cb018d5233 //owner所属值
}得到该值后,该owner所属的进程是一个PID为1387203的Java进程，该进程可以看到是jbd2处理transaction的过程中出现了异常：进程在等待Journal Transaction Commit
crash> bt 0xffff94cb018d5230
PID: 1387203 TASK: ffff94cb018d5230 CPU: 30 COMMAND: "java"
#0 [ffff94cb018cb8f8] \\_\\_schedule at ffffffffb31858fa
#1 [ffff94cb018cb988] schedule at ffffffffb3185da9
#2 [ffff94cb018cb998] wait\\_transaction\\_locked at ffffffffc04f8085 [jbd2]
#3 [ffff94cb018cb9f0] add\\_transaction\\_credits at ffffffffc04f8368 [jbd2]
#4 [ffff94cb018cba50] start\\_this\\_handle at ffffffffc04f85e1 [jbd2]
#5 [ffff94cb018cbae8] jbd2\\_\\_journal\\_start at ffffffffc04f8a93 [jbd2]
#6 [ffff94cb018cbb30] \\_\\_ext4\\_journal\\_start\\_sb at ffffffffc067d679 [ext4]
#7 [ffff94cb018cbb70] ext4\\_dirty\\_inode at ffffffffc065106a [ext4]
#8 [ffff94cb018cbb90] \\_\\_mark\\_inode\\_dirty at ffffffffb2c7e55d
#9 [ffff94cb018cbbc8] update\\_time at ffffffffb2c6aec9
#10 [ffff94cb018cbbf8] file\\_update\\_time at ffffffffb2c6afb0
#11 [ffff94cb018cbc38] ext4\\_page\\_mkwrite at ffffffffc06512bd [ext4]
#12 [ffff94cb018cbc90] do\\_page\\_mkwrite at ffffffffb2bee06a
#13 [ffff94cb018cbd10] do\\_wp\\_page at ffffffffb2bf1b27
#14 [ffff94cb018cbdb8] handle\\_mm\\_fault at ffffffffb2bf5e82
#15 [ffff94cb018cbe80] \\_\\_do\\_page\\_fault at ffffffffb318d653
#16 [ffff94cb018cbef0] trace\\_do\\_page\\_fault at ffffffffb318da26
#17 [ffff94cb018cbf30] do\\_async\\_page\\_fault at ffffffffb318cfa2
#18 [ffff94cb018cbf50] async\\_page\\_fault at ffffffffb31897a8
RIP: 00007fba56cf230e RSP: 00007fba29de7da0 RFLAGS: 00010216
RAX: 0000000002b94888 RBX: 00007fba57e98420 RCX: 0000000000000002
RDX: 00007fba566540e0 RSI: 00007fba5735ffec RDI: 00007fba5001eb90
RBP: 00007fba29de7db0 R8: 0000000000000003 R9: 0000000000000032
R10: 00000000000073b2 R11: 000b1a759ff75bcd R12: 0000000000000008
R13: 00007fba50020d90 R14: 0000000000000002 R15: 0000000000000001
ORIG\\ RAX: ffffffffffffffff CS: 0033 SS: 002b
crash>
crash> task\\_struct.sched\\_info 0xffff94cb018d5230
sched\\_info = {
pcount = 59975484,
run\\_delay = 1415791995,
last\\_arrival = 4453057373285825,
last\\_queued = 0
}
crash> log |grep sysrq
[4653942.472357] IP: [<ffffffffb2e738f6>] sysrq\\_handle\\_crash+0x16/0x20
[4653942.472357] RIP: 0010:[<ffffffffb2e738f6>] [<ffffffffb2e738f6>] sysrq\\_handle\\_crash+0x16/0x20
[4653942.472357] [<ffffffffb2e7411d>] \\_\\_handle\\_sysrq+0x10d/0x170
[4653942.472357] [<ffffffffb2e74533>] sysrq\\_filter+0x363/0x390
[4653942.472357] RIP [<ffffffffb2e738f6>] sysrq\\_handle\\_crash+0x16/0x20正在处理Transaction Commit的容器进程788315因为pod cgroup内存耗尽导致分配不到内存卡住，之所以卡住而不是触发oom kill的原因是进程788315触发了oom，但是__getblk这里因为满足不了退出死循环条件导致进程无法退出到handle_mm_fault调用oom kill：
其所在的容器pod id为：pod2e7583c6-a4bc-4b24-8b2b-5bd1d86c576b
至此，触发机器hung死的原因是pod mobile-mfanxing-home-6747c88777-hl7vj内存使用超过mem limit触发了centos7内核bug。社区上游有看到类似的case：https://bugs.centos.org/view.php?id=17982。
该bug当前为被修复，其触发的根因是在ext4文件系统下，因为cgroup oom而导致内核journnal模块调用时触发死锁，导致内核文件系统卡死。读IO高的原因是什么呢？至今依旧是个谜，由于内核hung死之后，系统内部无法检测到IO的来由。
3. 案发重现
该问题能否通过复现方式验证呢？带着这个疑问，我们在云加社区找到了一篇相同的文章，由 OOM 引发的 ext4 文件系统卡死 ,并且提供了验证复现的方法，不过ext4-repro-with-write二进制文件有点问题，需要重新编译。通过复现的方法验证内核bug，采用3个场景进行测试验证：
- 使用3.10内核，文件系统为ext4，验证bug是否能复现
- 使用3.10内核，文件系统为xfs，验证xfs能否修复此bug
- 使用4.16内核，文件系统为ext4，验证高版本内核是否修复
3.1 准备复现环境
环境说明：准备好测试环境
|环境 |腾讯云CVM |
|:--|
|配置信息 |16核32G，SA3.4XLARGE3 |
|磁盘信息 |高性能云盘100G，vdb |
|操作系统 |CentOS Linux release 7.7.1908 (Core) |
|内核版本 |3.10.0-1062.18.1.el7.x86_64 |
此次环境复现一共包含有3个文件：
- ext4-repro-with-multiple-cgroup.sh，总入口调用fio和触发cgroup oom
- ext4-repro-with-write,打开 ext4 文件系统上的文件，并不断地对该文件做写操作，过程中会涉及到 ext4 inode 内部的一些内存分配操作
- ext4-repro-with-write.go,源码程序文件，不需要使用，其定义了/usr/share/fxck路径，需要把数据盘挂载至该路径测试
脚本的功能如下：
- 准备一个测试程序 ext4-repro-with-write，打开 ext4 文件系统上的文件，并不断地对该文件做写操作，过程中会涉及到 ext4 inode 内部的一些内存分配操作；测试的 cgroup 中只有这一类进程，OOM Kill 的只可能是这类进程；
- 创建 10 个 cgroup，每个的内存限制为 100 MB；
- 对于每个 cgroup，创建 30 个 ext4-repro-with-write 进程；
ext4-repro-with-multiple-cgroup.sh脚本内容如下：
cat ext4-repro-with-multiple-cgroup.sh
#!/usr/bin/bash
echo "clean up"
systemctl stop ext4-repro-cgroup\\*-\\*
mkdir /usr/share/fxck/ -p
cp ext4-repro-with-write /usr/share/fxck/ext4-repro-with-write
chmod +x /usr/share/fxck/ext4-repro-with-write
for i in `seq 1 10`;do
echo "prepare cgroup"
cat << EOF > /etc/systemd/system/system-fio${i}.slice
[Unit]
Description=zbs Slice
Before=slices.target
Wants=system.slice
After=system.slice
EOF
mkdir /etc/systemd/system/system-fio${i}.slice.d -p
cat << EOF > /etc/systemd/system/system-fio${i}.slice.d/50-MemoryLimit.conf
[Slice]
MemoryLimit=104857600
EOF
systemctl daemon-reload
systemctl restart system-fio${i}.slice
systemctl status system-fio${i}.slice
echo "prepare fio data path"
TEST\\_PATH="/usr/share/ext4-repro"
mkdir $TEST\\_PATH
for j in `seq 1 30`;do
mkdir /etc/systemd/system/ext4-repro-cgroup${i}-${j}.service.d/ -p
cat << EOF > /etc/systemd/system/ext4-repro-cgroup${i}-${j}.service.d/cgroup.conf
[Service]
Slice=system-fio${i}.slice
EOF
cat << EOF > /usr/lib/systemd/system/ext4-repro-cgroup${i}-${j}.service
[Unit]
After=network.target、
[Service]
ExecStart=/usr/share/fxck/ext4-repro-with-write
Restart=always
RestartSec=3s
[Install]
WantedBy=multi-user.target
EOF
done
pushd /usr/lib/systemd/system
systemctl restart ext4-repro-cgroup${i}\\*.service
popd
doneext4-repro-with-write.go内容如下：
cat ext4-repro-with-write.go
package main
import (
"flag"
"fmt"
"math/rand"
"os"
"strconv"
"time"
)
const letterBytes = "abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ"
const path = "/usr/share/fxck/"
func RandStringBytes(n int) string {
b := make([]byte, n)
for i := range b {
b[i] = letterBytes[rand.Intn(len(letterBytes))]
}
return string(b)
}
func createFileName(path string) string {
name, \\_ := os.Hostname()
fn := path + name + strconv.Itoa(int(time.Now().Unix())) + RandStringBytes(8)
return fn
}
func w(path string) {
fn := createFileName(path)
fmt.Println(fn)
f, \\_ := os.OpenFile(fn, os.O\\_APPEND|os.O\\_CREATE|os.O\\_WRONLY, 0644)
fmt.Println(f)
defer os.Remove(fn)
defer f.Close()
for {
s := RandStringBytes(10)
\\_, \\_ = f.WriteString(s)
f.Sync()
}
}
func main() {
path := flag.String("path", "/usr/share/ext4-repo/", "a string")
flag.Parse()
fmt.Println("path:", \\*path)
go w(\\*path)
for {
time.Sleep(time.Duration(1) \\* time.Second)
}
}将数据盘/dev/vdb格式化为ext4文件系统，并将其挂载至/usr/share/fxck目录
mkfs.ext4 -f /dev/vdb
[root@VM-7-9-centos ~]# mount /dev/vdb /usr/share/fxck/
[root@VM-7-9-centos ~]# df -T /dev/vdb
文件系统 类型 1K-块 已用 可用 已用% 挂载点
/dev/vdb ext4 103080888 83420 97738204 1% /usr/share/fxck3.2 复现案发现场
运行脚本ext4-repro-with-multiple-cgroup.sh开始执行测试
bash ext4-repro-with-multiple-cgroup.sh运行脚本后，此时可以看到系统已经开了若干个ext4-repro-with进程，并且CPU负载会瞬间飙升
查看/var/log/message日志可以看到有频繁的OOM现象
观察进程此时可以看到jbd2/vdb-8进程处于僵死状态（D）
此时查看系统盘的监控，可以发现磁盘只读出现瞬间突增的现象，与案发现场现象完全吻合 ，由此可以进一步确认该bug是ext4文件系统在内核频繁oom而触发的内核bug。
出现异常后，操作系统处于hung死状态，机器无法登陆，只能通过强制重启的方式回复系统，如果如上脚本测试，约10-30min左右即可复现，复现频次高。
3.3 更换文件系统
导致系统hung死的原因是内核在提交Journal Transaction Commit时卡住，Journal模块是Linux kernel中同个通用模块，为ext4等文件系统所用，客户IDC环境采用xfs文件系统，并为出现过因OOM而引发的内核bug。
如果文件系统是xfs会出现相同的问题么，带着这个问题，我们继续进行验证，采用相同的测试脚本，将文件系统更换为xfs之后，看是否还会出现异常现象，更换数据盘的文件系统格式
# systemctl stop ext4-repro-cgroup\\*-\\*
# umount /dev/vdb
# mount /dev/vdb /usr/share/fxck/
# df -T /usr/share/fxck/
文件系统 类型 1K-块 已用 可用 已用% 挂载点
/dev/vdb xfs 104806400 32992 104773408 1% /usr/share/fxck准备好文件系统系统之后，重新运行测试脚本
# bash ext4-repro-with-multiple-cgroup.sh重新运行脚本会提示部分报错，由于之前已经存在systemd服务，可以忽略报错，通过ps可以看到ext4-repro-with相关的进程已经在系统中运行，同时vdb相关的进程状态也未出现僵死状态
https://km.woa.com/files/photos/pictures/202109/1631942107_84_w3078_h990.png
环境经过1周的时间测试，更换xfs文件系统之后测试发现，频繁OOM场景下不会触发内核bug导致系统夯死。相比于ext4 10min左右即可复现问题，效果显著，进一步可以说明该bug触发的场景。
3.4 更换内核版本
该内核bug是在3.10内核触发，因此更换内核也是一种解决方案，cgroup容器推广之后大范围开始使用，因此相较于更新版本的内核，3.10内核在处理cgroup oom的场景下相对没有那么健壮。根据线上客户实际运营经验来看，出现过不少因为cgroup oom而引发的bug，对于此类问题，根本的解决方案是升级至更新的内核版本，强烈推荐使用TencentOS内核。
将上述的操作系统更换为TencentOS内核，将文件系统重新更换为ext4进行测试,本文采用TencentOS Server 2.4系统，其内核为4.14.105版本，可以通过重装的方式更换：
https://km.woa.com/files/photos/pictures/202109/1631942216_13_w1568_h1624.png
重新将磁盘格式更换为ext4文件系统并挂载，重新运行测试脚本
mkfs.ext4 /dev/vdb
mkdir /usr/share/fxck/
mount /dev/vdb /usr/share/fxck/
# df -T /dev/vdb
文件系统 类型 1K-块 已用 可用 已用% 挂载点
/dev/vdb ext4 103080888 80300 97741324 1% /usr/share/fxck
bash ext4-repro-with-multiple-cgroup.sh更换TencentOS内核之后，测试一周后均无法复现内核bug，4.x的内核相比于3.10的内核，处理OOM场景更加健壮，可以说明在4.x之后的内核版本均已经修复该问题。
4. 真相大白
经过内核层面的分析以及环境复现和验证，真相终于浮出水面，可以得出如下结论：
- 3.10内核使用ext4文件系统，频繁oom触发内核bug；
- 3.10内核使用xfs文件系统，频发oom不会触发内核bug；
- TencentOS内核使用ext4文件系统，不会触发内核bug。
同时通过复现验证，可以知道：磁盘读高IO是由于内核夯死而引起，复现现象与实际故障一致！
5. 最佳实践
通过上面的分析和验证可知，客户当前该问题可以通过两种方法解决：
- 将ext4文件系统更换为xfs；
- 将操作系统内核升级至4.x版本
Cgroup自动docker出现之后逐步发扬光大，容器主要在3.10内核中开始大规模使用，相比于高版本的内核，cgroup内核代码处理并不太健壮。与之同时，容器环境设置了cgroup内存limits后，容器超过内存限制后OOM往往是常见的现象，因此出现OOM的概率相比于非容器环境会更加频繁。根据腾讯云线上的容器环境的运维，3.10内核出现内核问题较多，如下是一些同学整理的文章：
- cgroup OOM引发内核死锁问题分析
- cgroup oom引发容器重建问题分析
- 由 OOM 引发的 ext4 文件系统卡死
- 容器cgroup引发的内存泄漏问题分析
- iptables内核bug引发节点偶发宕机（文章暂未记录），目前已在等多个大客户环境中遇到，如有兴趣可以联系我获取资料。
当下是一个云原生的时代，kubernetes是当下不二的选择，越来越多的应用会选择运行在kubernetes环境上，容器的底层实现深度依赖于内核的众多特性。例如，overlay 文件系统、namespace 及 cgroup 等。因此内核的功能和稳定性，在很大程度上决定了整个容器 PaaS 平台的功能和稳定性。对于腾讯云上如何选择master和node节点的内核呢？强烈推荐TencentOS内核。
Tencent Linux 是腾讯官方运营的 Linux 版本，参考官网说明 。由腾讯专门的内核维护，专门针对云环境下优化的内核，且遇到问题会有专门的团队维护，相比于社区的修复速度可以大大提高，其优化的一些性能：
- 解决 IPVS 模式高并发场景下，连接复用引发连接异常的问题（#81775）。
- 解决 IPVS 模式在高配节点（核数多）下 IPVS 规则过多引发网络毛刺的问题。
- 解决在容器密集场景下（单节点上容器数量较多），cAdvisor 读取 memcg 陷入内核态过久引发网络毛刺的问题。
- 解决大 Pod（占用核数多，单核占用高）在高配节点（核数多）场景下，CPU 负载均衡引发网络毛刺的问题。
- 解决高并发场景下的 TCP 连接监控（例如单独部署 cAdvisor 配置监控 TCP 连接）引发网络周期性抖动问题。
- 优化网络收包软中断，提升网络性能。
相比于Linux内核上游社区，TencentOS内核具有以下优势：
- 提供热补丁更新，避免更换内核造成业务损伤；
- TKE集群中已经大量部署及验证；
- 针对不同容器客户进行性能优化沉淀，规避大部分已知问题；
- 基于开源代码进行功能、性能优化，代码本身也对外开源：https://github.com/Tencent/TencentOS-kernel。
写在最后
内核问题分析是个复杂而艰难的问题，作者全程参与了该问题的排查，抱着学习vmcore的心态，整理和分享处理该问题的过程，从内核问题分析到问题验证，给予容器内核选型参考和建议。
