由 OOM 引發(fā)的 ext4 文件系統(tǒng)卡死
注：本問題影響 3.10.0-862.el7.centos 及之后的 CentOS 7 版本內(nèi)核，目前問題還未被修復。
背景
近日，我司的測試同學發(fā)現(xiàn)內(nèi)部集群中一個存儲節(jié)點無法通過 ssh 訪問了。iDRAC console 界面出現(xiàn)如下圖的錯誤：有若干個服務(wù)進程由于 cgroup 超過內(nèi)存限制被 Kill，隨后許多進程陸續(xù)卡住，出現(xiàn) “task xxx blocked for more than 120 seconds”。此時，系統(tǒng)無法進行賬號登錄，似乎整個根文件系統(tǒng)（ext4）都卡住了。測試同學通過 ipmitool 工具發(fā)送 NMI 信號讓系統(tǒng)產(chǎn)生 vmcore（Linux 內(nèi)核崩潰時產(chǎn)生的內(nèi)核轉(zhuǎn)儲文件）以便后續(xù)分析，然后重啟機器讓業(yè)務(wù)恢復。
將多個服務(wù)放置在 cgroup 中，限制它們的內(nèi)存使用量；當內(nèi)存使用量超過預(yù)設(shè)上限值，OOM（Out-of-Memory） Killer 按照一定策略 Kill 掉部分進程，實現(xiàn)內(nèi)存釋放。這是很常規(guī)的操作，如 Red Hat Enterprise Linux Resource Management Guide - memory（https://access.redhat.com/documentation/en-us/red_hat_enterprise_linux/6/html/resource_management_guide/sec-memory）。
從內(nèi)存使用量的監(jiān)控圖表中，我們確定了系統(tǒng)中某個服務(wù)存在內(nèi)存占用隨著實例數(shù)增加而線性增長的 bug。但是，為什么 OOM 會導致 ext4 文件系統(tǒng)卡死呢？
相關(guān)問題檢索
從日志和采集到的 vmcore 中，發(fā)現(xiàn)有許多進程都卡在 ext4/jbd2 的 I/O 操作上。其中 jbd2 （Journaling block device）是 kernel 中通用的 journal 模塊，被 ext4 使用。從日志中可以看出，OOM 后不久就觸發(fā)許多進程卡住，可以推斷 OOM 與 ext4 卡住存在很強的關(guān)聯(lián)性。
為此，找到如下一些 RedHat 官方關(guān)于 ext4/jbd2 的 KB，但經(jīng)過版本和調(diào)用棧比對，我們排除了它們，看上去這是一個新的問題。
Hung task "jbd2/dm-16-8" in jbd2_journal_commit_transaction() when issuing I/O through a software RAID or mirror device（https://access.redhat.com/solutions/3226391）
RHEL7: jbd2 deadlock occurs while checkpoint thread waits commit thread to finish（https://access.redhat.com/solutions/4054181）.
嘗試復現(xiàn)
嘗試根據(jù)現(xiàn)有線索構(gòu)建復現(xiàn)腳本，方便后續(xù) debug 分析和假想驗證。一旦復現(xiàn)問題，就可以生成 vmcore 做分析。然而，vmcore 只能記錄產(chǎn)生 vmcore 時刻的快照信息，犯罪進程可能已經(jīng)逃離現(xiàn)場，此時更詳細的日志可以幫助恢復現(xiàn)場。因此，我們還開啟了 jbd2 模塊日志功能，重新編譯內(nèi)核。
初次嘗試
根據(jù)網(wǎng)上一些相似問題的討論，我們最初的猜想是 cgroup 內(nèi)的進程在做 ext4 I/O 操作時，可能由于內(nèi)存限制無法申請到內(nèi)存后忘記釋放文件系統(tǒng)的某些關(guān)鍵資源，導致其他進程（可能是 cgroup 內(nèi)，也可能不處于 cgroup 中）ext4 I/O 操作無法進行。于是，有了以下復現(xiàn)方法：
在 cgroup 中有兩類進程，一類不斷分配內(nèi)存，在 15s 左右達到 cgroup 的內(nèi)存限制；另一類跑 fio，對 ext4 分區(qū)的文件做大塊隨機寫操作。每類進程各 3 個；如果進程被 OOM Kill，會被 systemd 重新拉起； 在 cgroup 之外，有另外 3 個 fio 進程，對 ext4 分區(qū)的其他文件做大塊隨機寫操作；
經(jīng)歷了 7 個小時左右，我們復現(xiàn)了一次，卡住現(xiàn)象與最初現(xiàn)場一致。但隨后一天中，4 個節(jié)點都沒法再次復現(xiàn)，需要找到加速復現(xiàn)的方式。
再次嘗試
由于前兩次復現(xiàn)的場景最后被 OOM Kill 的進程都是 IO 進程，而上述復現(xiàn)步驟中經(jīng)常被 Kill 的是分配內(nèi)存的進程，因此考慮做以下調(diào)整：
準備一個測試程序 ext4-repro-with-write，打開 ext4 文件系統(tǒng)上的文件，并不斷地對該文件做寫操作，過程中會涉及到 ext4 inode 內(nèi)部的一些內(nèi)存分配操作；測試的 cgroup 中只有這一類進程，OOM Kill 的只可能是這類進程； 創(chuàng)建 10 個 cgroup，每個的內(nèi)存限制為 100 MB； 對于每個 cgroup，創(chuàng)建 30 個 ext4-repro-with-write 進程；
使用這一腳本，我們能夠在 10 分鐘以內(nèi)復現(xiàn)這個問題。相關(guān)復現(xiàn)腳本已經(jīng)上傳到 https://gist.github.com/jiewei-ke/4962ac0061703fdcd0837bab2dbec261。
確定影響版本
分別測試 CentOS 7 的幾個官方內(nèi)核版本以及 CentOS 8 的 4.18 內(nèi)核，我們確定：
CentOS 7 3.10.0-693.el7 版本沒有問題； CentOS 7 3.10.0-862.el7 及后續(xù)版本（包含最新的 3.10.0-1160.el7）都有問題； CentOS 8 4.18.0 版本沒有問題；
即該問題是 CentOS 7 3.10.0-862.el7 引入的。
vmcore 分析
獲取到帶有 jbd2 模塊日志的 vmcore 后，下面使用 crash 工具對其進行分析。
注：分析過程比較冗長，對于 vmcore 分析不感興趣的同學可以直接跳到 Recap 部分看結(jié)論。
ext4/jbd2 簡介
參考 Linux: The Journaling Block Device（https://web.archive.org/web/20070926223043/http://kerneltrap.org/node/6741），ext4 文件系統(tǒng)基于 jbd2 以 WAL（write-ahead logging）形式更新元數(shù)據(jù)，防止系統(tǒng) crash 時發(fā)生元數(shù)據(jù)損壞。每一個 ext4 文件系統(tǒng)實例對應(yīng)一個 jbd2 Journal 實例。每個用戶線程的一次數(shù)據(jù)更新稱為一個 Handle，在時間上連續(xù)的多個 Handle（可能來自不同線程）組成一個 Transaction，以便實現(xiàn)批量提交。Transaction 提交滿足原子性。
Journal 包括兩個階段，Commit 和 Checkpoint。Commit 負責提交修改，由用戶線程和內(nèi)核 Journal 線程配合完成。
當用戶程序?qū)?ext4 文件系統(tǒng)做文件操作（例如 create()）時，用戶線程先獲取 Handle，然后獲取 Journal 當前的 running Transaction，如果存在則使用它，不存在則新創(chuàng)建一個。同時原子增加 running Transaction 的 t_updates 計數(shù)，表示該 Transaction 被多少個線程使用。隨后，用戶線程將修改的元數(shù)據(jù)內(nèi)容加入到 Transaction 的 buffer 鏈表中，遞減 t_updates。 內(nèi)核的 Journal 線程會定期喚醒，將 Journal 的 running Transaction 變?yōu)?committing 狀態(tài)，然后等待 t_updates 歸零，即等待用戶線程完成插入 buffer 鏈表。隨后將 buffer 鏈表合并寫入到對應(yīng)的 Journal 區(qū)域。隨后該 Transaction 加入等待 checkpoint 的 Transaction 列表中。 以上過程中，每個 Journal 實例同時只有一個 running Transaction 和一個 committing Transaction。
Checkpoint 負責持久化修改，由用戶線程發(fā)起。用戶線程從待 checkpoint 的 Transaction 列表中獲取 buffer，然后合并寫入到物理磁盤，Transaction 至此結(jié)束。
以上描述只關(guān)注本文涉及到的步驟。更詳細的過程請參考 High-Performance Transaction Processing in Journaling File Systems（https://www.usenix.org/system/files/conference/fast18/fast18-son.pdf） 的 Background 部分。
進程堆棧分析
針對 vmcore，通過 crash 命令 ”foreach bt > bt.log“ 獲得所有進程的堆棧信息。根據(jù) jbd2 關(guān)鍵字過濾進程，主要有以下幾類：
類別 1：內(nèi)核的 Journal 線程卡在等待 t_updates 歸零
上文提到，內(nèi)核 Journal 線程進行 Commit 之前需要先等待 t_updates 歸零。下圖的 Journal 線程正是卡在等待 t_updates 歸零的循環(huán)中，說明此時有一個用戶進程正在發(fā)起 Commit 操作，但是還沒有完成 buffer 鏈表的更新。
PID: 587 TASK: ffff9f53f8c31070 CPU: 5 COMMAND: "jbd2/md127-8"
#0 [ffff9f53ff35bbf0] __schedule at ffffffffb139e420
#1 [ffff9f53ff35bc88] schedule at ffffffffb139eb09
#2 [ffff9f53ff35bc98] jbd2_journal_commit_transaction at ffffffffc01fe8b0 [jbd2]
#3 [ffff9f53ff35be40] kjournald2 at ffffffffc0205c5e [jbd2]
#4 [ffff9f53ff35bec8] kthread at ffffffffb0cc6bd1
/*
* jbd2_journal_commit_transaction
*
* The primary function for committing a transaction to the log. This
* function is called by the journal thread to begin a complete commit.
*/
void jbd2_journal_commit_transaction(journal_t *journal)
{
// ...
while (atomic_read(&commit_transaction->t_updates)) { <<< 在這循環(huán)
DEFINE_WAIT(wait);
prepare_to_wait(&journal->j_wait_updates, &wait,
TASK_UNINTERRUPTIBLE);
if (atomic_read(&commit_transaction->t_updates)) {
spin_unlock(&commit_transaction->t_handle_lock);
write_unlock(&journal->j_state_lock);
schedule();
write_lock(&journal->j_state_lock);
spin_lock(&commit_transaction->t_handle_lock);
}
finish_wait(&journal->j_wait_updates, &wait);
}
類別 2：等待 Transaction Commit 完成的進程
有 3 個進程，它們都在等待 Transaction Commit 的完成。jbd2_log_wait_commit() 正在等待 j_wait_done_commit，該鎖正被類別 1 的 Journal 線程持有，只有當 Journal 線程完成 jbd2_journal_commit_transaction() 時，才會釋放 j_wait_done_commit。因此，這 3 個進程也是被動卡住的線程，正在等待 Journal 線程。
PID: 27153 TASK: ffff9f53fc35a0e0 CPU: 5 COMMAND: "ext4-repro-with-write"
#0 [ffff9f526e04fd70] __schedule at ffffffffb139e420
#1 [ffff9f526e04fe08] schedule at ffffffffb139eb09
#2 [ffff9f526e04fe18] jbd2_log_wait_commit at ffffffffc02054a5 [jbd2]
#3 [ffff9f526e04fe98] jbd2_complete_transaction at ffffffffc0206e21 [jbd2]
#4 [ffff9f526e04feb8] ext4_sync_file at ffffffffc03cff60 [ext4]
#5 [ffff9f526e04ff00] do_fsync at ffffffffb0e8ccf7
#6 [ffff9f526e04ff40] sys_fsync at ffffffffb0e8cff0
#7 [ffff9f526e04ff50] system_call_fastpath at ffffffffb13ac81e
類別 3：等待 Commit Transaction 的用戶進程
這類有 32 個進程，數(shù)量比較多，都卡在 jbd2__journal_start() -> wait_transaction_locked() 上，在 Commit Transaction 的早期階段。這些進程都是被動卡住的，不是事發(fā)原因。
PID: 906 TASK: ffff9f53fa13b150 CPU: 5 COMMAND: "loop0"
#0 [ffff9f53fb7cf830] __schedule at ffffffffb139e420
#1 [ffff9f53fb7cf8c8] schedule at ffffffffb139eb09
#2 [ffff9f53fb7cf8d8] wait_transaction_locked at ffffffffc01fb085 [jbd2]
#3 [ffff9f53fb7cf930] add_transaction_credits at ffffffffc01fb360 [jbd2]
#4 [ffff9f53fb7cf990] start_this_handle at ffffffffc01fb63f [jbd2]
#5 [ffff9f53fb7cfa48] jbd2__journal_start at ffffffffc01fbbb6 [jbd2]
#6 [ffff9f53fb7cfa90] __ext4_journal_start_sb at ffffffffc0409c89 [ext4]
#7 [ffff9f53fb7cfad0] ext4_dirty_inode at ffffffffc03dc9da [ext4]
#8 [ffff9f53fb7cfaf0] __mark_inode_dirty at ffffffffb0e87280
#9 [ffff9f53fb7cfb28] update_time at ffffffffb0e7484a
#10 [ffff9f53fb7cfb58] file_update_time at ffffffffb0e74961
#11 [ffff9f53fb7cfba0] __generic_file_aio_write at ffffffffb0dc4eac
#12 [ffff9f53fb7cfc20] generic_file_aio_write at ffffffffb0dc5109
#13 [ffff9f53fb7cfc60] ext4_file_write at ffffffffc03cfb8e [ext4]
#14 [ffff9f53fb7cfcd8] do_sync_write at ffffffffb0e54936
#15 [ffff9f53fb7cfdb0] __do_lo_send_write at ffffffffc0597045 [loop]
#16 [ffff9f53fb7cfdf8] do_lo_send_direct_write at ffffffffc0597156 [loop]
#17 [ffff9f53fb7cfe30] loop_thread at ffffffffc0598382 [loop]
#18 [ffff9f53fb7cfec8] kthread at ffffffffb0cc6bd1
在以上 3 種類別中，類別 1 內(nèi)核的 Journal 線程卡住是導致其他進程卡住的原因，此時整個 ext4 文件系統(tǒng)的文件操作都無法繼續(xù)。下面著重分析該進程。
內(nèi)核的 Journal 線程分析
首先檢查當前 Journal 的狀況。crash 切換到內(nèi)核 Journal 線程，顯示每個 stack frame 的參數(shù)寄存器內(nèi)容，主要關(guān)注 jbd2_journal_commit_transaction()。嘗試解析各個地址，發(fā)現(xiàn) ffff9f4539ac9000 能夠正確解析為 journal_t 類型（也可以根據(jù)反匯編確定參數(shù)是如何傳遞的），拿到 Journal 的指針。
crash> mod -s jbd2
MODULE NAME SIZE OBJECT FILE
ffffffffc02100e0 jbd2 117134 /lib/modules/3.10.0-1.el7.x86_64/kernel/fs/jbd2/jbd2.ko
crash> set 587
PID: 587
COMMAND: "jbd2/md127-8"
TASK: ffff9f53f8c31070 [THREAD_INFO: ffff9f53ff358000]
CPU: 5
STATE: TASK_UNINTERRUPTIBLE
crash> bt
PID: 587 TASK: ffff9f53f8c31070 CPU: 5 COMMAND: "jbd2/md127-8"
#0 [ffff9f53ff35bbf0] __schedule at ffffffffb139e420
#1 [ffff9f53ff35bc88] schedule at ffffffffb139eb09
#2 [ffff9f53ff35bc98] jbd2_journal_commit_transaction at ffffffffc01fe8b0 [jbd2]
#3 [ffff9f53ff35be40] kjournald2 at ffffffffc0205c5e [jbd2]
#4 [ffff9f53ff35bec8] kthread at ffffffffb0cc6bd1
crash> bt -fl
PID: 587 TASK: ffff9f53f8c31070 CPU: 5 COMMAND: "jbd2/md127-8"
#0 [ffff9f53ff35bbf0] __schedule at ffffffffb139e420
...
#1 [ffff9f53ff35bc88] schedule at ffffffffb139eb09
/usr/src/debug/kernel-ml-3.10.0/linux-3.10.0-1.el7.x86_64/kernel/sched/core.c: 3654
ffff9f53ff35bc90: ffff9f53ff35be38 ffffffffc01fe8b0
#2 [ffff9f53ff35bc98] jbd2_journal_commit_transaction at ffffffffc01fe8b0 [jbd2]
…
ffff9f53ff35be10: ffff9f4539ac9028 ffff9f4539ac93e8
ffff9f53ff35be20: ffff9f4539ac90a8 ffff9f53ff35be80
ffff9f53ff35be30: ffff9f4539ac9000 ffff9f53ff35bec0 // 能夠正確解析為 Journal 的地址
ffff9f53ff35be40: ffffffffc0205c5e
#3 [ffff9f53ff35be40] kjournald2 at ffffffffc0205c5e [jbd2]
ffff9f53ff35be48: ffff9f5316aa0f62 ffff9f53f8c31070
ffff9f53ff35be58: ffff9f53f8c31070 ffff9f4539ac9090
...
#4 [ffff9f53ff35bec8] kthread at ffffffffb0cc6bd1
/usr/src/debug/kernel-ml-3.10.0/linux-3.10.0-1.el7.x86_64/kernel/kthread.c: 202
crash> journal_t.j_devname ffff9f4539ac9000
j_devname = "md127-8\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000"
獲取 Journal 的 running Transaction 0xffff9f53d4ec1900，可以看到它的 t_updates 為 1，因此處于循環(huán)等待中。
crash> journal_t.j_running_transaction ffff9f4539ac9000
j_running_transaction = 0xffff9f53d4ec1900
crash> transaction_t 0xffff9f53d4ec1900
struct transaction_t {
t_journal = 0xffff9f4539ac9000,
t_tid = 380243810,
t_state = T_LOCKED,
...
t_updates = {
counter = 1 // t_updates 為 1，處于循環(huán)等待
},
t_outstanding_credits = {
counter = 56
},
…
}
提交 Transaction 的用戶進程分析
t_updates 的更新是由提交 Transaction 的用戶進程完成的。下面看一下其更新流程。
t_updates 遞增的過程
在 Transaction 被提交前，用戶進程會先通過 jbd2__journal_start() 獲取當前進程的 Handle，隨后調(diào)用 start_this_handle() 為 Transaction 預(yù)留需要的 Journal 空間。
static inline handle_t *journal_current_handle(void)
{
return current->journal_info;
}
handle_t *jbd2__journal_start(journal_t *journal, int nblocks, int rsv_blocks,
gfp_t gfp_mask, unsigned int type,
unsigned int line_no)
{
handle_t *handle = journal_current_handle(); // 獲取進程的 Handle
...
err = start_this_handle(journal, handle, gfp_mask);
在 start_this_handle() 中，我們看到 Handle 中保存了 running Transaction 的指針，同時 Transaction 的 t_updates 被原子加一。
static int start_this_handle(journal_t *journal, handle_t *handle,
gfp_t gfp_mask)
{
...
transaction = journal->j_running_transaction;
...
update_t_max_wait(transaction, ts);
handle->h_transaction = transaction;
handle->h_requested_credits = blocks;
handle->h_start_jiffies = jiffies;
atomic_inc(&transaction->t_updates);
atomic_inc(&transaction->t_handle_count);
t_updates 遞減的過程
相對應(yīng)的，Transaction 的 t_updates 是由 jbd2_journal_stop 中遞減的。
int jbd2_journal_stop(handle_t *handle)
{
...
/*
* Once we drop t_updates, if it goes to zero the transaction
* could start committing on us and eventually disappear. So
* once we do this, we must not dereference transaction
* pointer again.
*/
tid = transaction->t_tid;
if (atomic_dec_and_test(&transaction->t_updates)) {
wake_up(&journal->j_wait_updates);
if (journal->j_barrier_count)
wake_up(&journal->j_wait_transaction_locked);
}
t_updates 為何沒有歸零？
我們找一下是否有 Handle 持有著這個 Transaction。事先添加的 jbd2 模塊日志會打印出 Handle 相關(guān)日志，檢索日志中曾經(jīng)出現(xiàn)過的 Handle 指針如下，
$ grep jbd2_journal_stop vmcore-dmesg.txt | grep Handle | awk '{print $7}' | sort | uniq
...
ffff9f53f9676cf0
ffff9f53fa89bb70
ffff9f53fe3423c0
逐個嘗試解析 Handle，發(fā)現(xiàn) Handle ffff9f53fa89bb70 正在處理上述的 Transaction ?0xffff9f53d4ec1900。其中，h_line_no 為 2264，即該 Handle 是在行號為 2264 的代碼啟動的（但沒有包含文件名信息）。
crash> handle_t ffff9f53fa89bb70
struct handle_t {
{
h_transaction = 0xffff9f53d4ec1900,
h_journal = 0xffff9f53d4ec1900 // 這里好像填錯了，跟 transaction 是一樣的。。
},
h_rsv_handle = 0x0,
h_buffer_credits = 33,
h_ref = 1,
h_err = 0,
h_sync = 0,
h_jdata = 0,
h_reserved = 0,
h_aborted = 0,
h_type = 4,
h_line_no = 2264,
h_start_jiffies = 4298558935,
h_requested_credits = 35
}
在 ext4 代碼中，發(fā)現(xiàn) ext4_create() 中調(diào)用 ext4_new_inode_start_handle() 的行號正好與之匹配。根據(jù)代碼，ext4_new_inode_start_handle() 會調(diào)用 jbd2__journal_start() 將 t_updates 加一，然后將 inode 元數(shù)據(jù)信息更新加入 Transaction。之后，ext4_create() 調(diào)用 ext4_journal_stop() 將 t_updates 減一。
static int ext4_create(struct inode *dir, struct dentry *dentry, umode_t mode,
bool excl)
{
handle_t *handle;
struct inode *inode;
int err, credits, retries = 0;
dquot_initialize(dir);
credits = (EXT4_DATA_TRANS_BLOCKS(dir->i_sb) +
EXT4_INDEX_EXTRA_TRANS_BLOCKS + 3);
retry:
inode = ext4_new_inode_start_handle(dir, mode, &dentry->d_name, 0,
NULL, EXT4_HT_DIR, credits); // 在這里卡住了
handle = ext4_journal_current_handle();
err = PTR_ERR(inode);
if (!IS_ERR(inode)) {
inode->i_op = &ext4_file_inode_operations;
inode->i_fop = &ext4_file_operations.kabi_fops;
ext4_set_aops(inode);
err = ext4_add_nondir(handle, dentry, inode);
if (!err && IS_DIRSYNC(dir))
ext4_handle_sync(handle);
}
if (handle)
ext4_journal_stop(handle); // 還沒有調(diào)用
if (err == -ENOSPC && ext4_should_retry_alloc(dir->i_sb, &retries))
goto retry;
return err;
}
t_updates 沒有歸零，說明 ext4_journal_stop() 沒有調(diào)用。如果 Handle 還沒有執(zhí)行 jbd2_journal_stop()，那么它會被某個進程所持有，保存在進程控制塊 task_struct 的 journal_info 中。通過搜索所有進程的 task_struct，可以看到 task 27225（我們的測試程序 ext4-repro-with-write）進程正在持有這個 Handle。
crash> foreach task > task.log
crash> task 27225 | grep journal_info
journal_info = 0xffff9f53fa89bb70,
crash> ps | grep 27225
27225 1 4 ffff9f533a6d3150 RU 0.0 239712 38800 ext4-repro-with-write
crash> bt 27225
PID: 27225 TASK: ffff9f533a6d3150 CPU: 4 COMMAND: "ext4-repro-with-write"
#0 [ffff9f53c234f900] __schedule at ffffffffb139e420
#1 [ffff9f53c234f990] sys_sched_yield at ffffffffb0cdafdc
#2 [ffff9f53c234f9b0] yield at ffffffffb139fca2
#3 [ffff9f53c234f9c8] free_more_memory at ffffffffb0e8ee2c
#4 [ffff9f53c234fa08] __getblk at ffffffffb0e90013
#5 [ffff9f53c234fa70] __ext4_get_inode_loc at ffffffffc03d358f [ext4]
#6 [ffff9f53c234fad8] ext4_reserve_inode_write at ffffffffc03d8e62 [ext4]
#7 [ffff9f53c234fb08] ext4_mark_inode_dirty at ffffffffc03d8f23 [ext4]
#8 [ffff9f53c234fb60] ext4_ext_tree_init at ffffffffc04038ba [ext4]
#9 [ffff9f53c234fb70] __ext4_new_inode at ffffffffc03d271b [ext4]
#10 [ffff9f53c234fc18] ext4_create at ffffffffc03e3fb3 [ext4]
#11 [ffff9f53c234fc90] vfs_create at ffffffffb0e62aa8
#12 [ffff9f53c234fcc8] do_last at ffffffffb0e67e5f
#13 [ffff9f53c234fd70] path_openat at ffffffffb0e681e0
#14 [ffff9f53c234fe08] do_filp_open at ffffffffb0e69d6d
#15 [ffff9f53c234fee0] do_sys_open at ffffffffb0e5442e
#16 [ffff9f53c234ff40] sys_openat at ffffffffb0e54504
#17 [ffff9f53c234ff50] system_call_fastpath at ffffffffb13ac81e
ext4-repro-with-write 進程處于 RUNNING 狀態(tài)，正在執(zhí)行 ext4_create -> ext4_new_inode_start_handle -> __ext4_new_inode，此時 t_updates 已經(jīng)加一，但是由于 ext4_new_inode_start_handle() 還沒有結(jié)束，后續(xù)的 ext4_journal_stop() 也沒有執(zhí)行，故 t_updates 沒有歸零。
問題出在 ext4_new_inode_start_handle()，如果 __get_blk() 獲取不到內(nèi)存時，會不斷地嘗試調(diào)用 free_more_memory() 釋放掉部分內(nèi)存（事實證明釋放并沒有成功），然后再嘗試獲取。如果一直獲取不到，那么將會卡在這里。
get_blk 為何分配不到內(nèi)存？
與前文的復現(xiàn)腳本略微有些差異，這個測試中 ext4-repro-with-write 內(nèi)部包含兩個線程，一個負責不斷分配內(nèi)存，另一個負責持續(xù)寫文件。在內(nèi)存限制為 900MB 左右的 cgroup 中啟動了 3 個進程。
$cat /etc/systemd/system/system-fio.slice.d/50-MemoryLimit.conf
[Slice]
MemoryLimit=973741824
>>> 973741824/1024.0/1024
928.632568359375 // 900MB 左右
按照 task group 方式檢查當前 3 個 ext4-repro-with-write 進程的內(nèi)存使用量，可以看到內(nèi)存使用已經(jīng)接近 cgroup 內(nèi)存限制，提交 Transaction 的 task 27225 所在的 group 只占用了 37 MB，而另外兩個進程各自占用 400 MB 以上。
crash> ps -G ext4-repro-with-write | sed 's/>//g' | sort -k 8,8 -n | awk '$8 ~ /[0-9]/{ $8 = $8/1024" MB"; print }'
27222 1 5 ffff9f53b5b9b150 RU 0.0 239712 37.8906 MB ext4-repro-with-write // 27225 所在的 group
27189 1 5 ffff9f52357c1070 IN 0.3 578292 403.246 MB ext4-repro-with-write
27153 1 5 ffff9f53fc35a0e0 UN 0.4 848900 487.488 MB ext4-repro-with-write // 需要被 Kill 的進程
>>> 37.8906+403.246+487.488
928.6246
從 vmcore-dmesg 日志看，最近一次觸發(fā) OOM Kill 的進程是 27153 ，但是內(nèi)存并沒有降下來。
[ 3891.873807] Memory cgroup out of memory: Kill process 27158 (ext4-repro-with-write) score 511 or sacrifice child
[ 3891.875313] Killed process 27153 (ext4-repro-with-write), UID 0, total-vm:848900kB, anon-rss:499124kB, file-rss:868kB, shmem-rss:0kB
看一下 27153 進程，處于 UN 狀態(tài)而無法接受 Kill 信號，所以內(nèi)存不可能得到釋放。
crash> ps ext4-repro-with-write
PID PPID CPU TASK ST %MEM VSZ RSS COMM
27153 1 5 ffff9f53fc35a0e0 UN 0.4 848900 499188 ext4-repro-with-write
如下圖，該進程屬于上述類型 2 的進程，它正在等到內(nèi)核 Journal 線程完成 Commit，死鎖條件成立。
crash> bt 27153
PID: 27153 TASK: ffff9f53fc35a0e0 CPU: 5 COMMAND: "ext4-repro-with-write"
#0 [ffff9f526e04fd70] __schedule at ffffffffb139e420
#1 [ffff9f526e04fe08] schedule at ffffffffb139eb09
#2 [ffff9f526e04fe18] jbd2_log_wait_commit at ffffffffc02054a5 [jbd2]
#3 [ffff9f526e04fe98] jbd2_complete_transaction at ffffffffc0206e21 [jbd2]
#4 [ffff9f526e04feb8] ext4_sync_file at ffffffffc03cff60 [ext4]
#5 [ffff9f526e04ff00] do_fsync at ffffffffb0e8ccf7
#6 [ffff9f526e04ff40] sys_fsync at ffffffffb0e8cff0
#7 [ffff9f526e04ff50] system_call_fastpath at ffffffffb13ac81e
Recap
根據(jù)以上冗長的分析，OOM 導致 ext4 文件系統(tǒng)死鎖的時間線整理如下：
系統(tǒng)內(nèi)有兩個用戶進程，位于同一個 cgroup 中，cgroup 上限制最大可用的內(nèi)存； 進程 1，分配大量內(nèi)存，使得 cgroup 內(nèi)存使用量超過限制，OOM Killer 選擇該進程殺死；該進程正在執(zhí)行 ext4_sync_file()，在 jbd2_log_wait_commit() 等待進程 2 的 Transaction 完成；此時該進程處于不可中斷狀態(tài)，無法被 Kill，內(nèi)存無法被釋放； 進程 2，處于 ext4_create()（或者其他 ext4_xxx 函數(shù)）中，在 __getblk() 上等待可用的內(nèi)存；只有拿到足夠內(nèi)存，才能完成 ext4_journal_stop()，將 t_updates 遞減，其對應(yīng)的內(nèi)核 Journal 線程才能完成 jbd2_journal_commit_transaction()； （死鎖條件 1）進程 1 在等待進程 2 的 Transaction Commit 完成才能被 Kill 而釋放內(nèi)存；（死鎖條件 2）進程 2 在等待進程 1 的釋放內(nèi)存才能拿到內(nèi)存完成 Transaction Commit。
解決方案
在上述兩個死鎖條件中，只要我們破壞一個條件就可以避免死鎖發(fā)生。條件 1 是 jbd2 的實現(xiàn)要求，我們難以改變；條件 2 則有可能打破，例如，針對這種關(guān)鍵路徑上的內(nèi)存分配，允許 cgroup 的內(nèi)存暫時超過限制。
Linux VMM（Virtual Memory Manager）提供了 Get Free Page（GFP）Flags 來控制分配器的分配、釋放行為。其中有一個 Flag 名為 __GFP_NOFAIL，在 2.6 內(nèi)核版本加入，其作用是 “This flag is used by a caller to indicate that the allocation should never fail and the allocator should keep trying to allocate indefinitely”。根據(jù)代碼確認，如果分配內(nèi)存時 gfp_mask 攜帶了 __GFP_NOFAIL，那么 VMM 會盡量滿足分配需求，不再理會 cgroup 的內(nèi)存限制。更詳細的 GFP 說明請參考 Understanding the Linux Virtual Memory Manager: 6.4 ?Get Free Page (GFP) Flags（https://www.kernel.org/doc/gorman/html/understand/understand009.html#Sec:%20GFP%20Flags）。
我們看一下 __getblk() 的函數(shù)調(diào)用鏈，關(guān)鍵的函數(shù)如下，
__getblk
->__getblk_slow
->grow_buffers
->grow_dev_page
->find_or_create_page
->add_to_page_cache_lru
->__add_to_page_cache_locked
-> mem_cgroup_cache_charge
-> ...
->__mem_cgroup_try_charge
如下代碼所示，grow_dev_page() 在調(diào)用 find_or_create_page() 之前已經(jīng)攜帶了 __GFP_NOFAIL，按理來說，后續(xù)的內(nèi)存分配就不會受到 cgroup 限制了（__mem_cgroup_try_charge() ）。但為什么 __getblk() 還是沒有成功呢？
static int
grow_dev_page(struct block_device *bdev, sector_t block,
pgoff_t index, int size, int sizebits)
{
...
gfp_mask = mapping_gfp_mask(inode->i_mapping) & ~__GFP_FS;
gfp_mask |= __GFP_MOVABLE;
/*
* XXX: __getblk_slow() can not really deal with failure and
* will endlessly loop on improvised global reclaim. Prefer
* looping in the allocator rather than here, at least that
* code knows what it's doing.
*/
gfp_mask |= __GFP_NOFAIL;
page = find_or_create_page(inode->i_mapping, index, gfp_mask);
if (!page)
return ret;
__GFP_NOFAIL 丟失
上文提到，3.10.0-862.el7.centos 是引入該問題的版本。我們對照 3.10.0-693.el7.centos 和 3.10.0-862.el7.centos 兩個版本在上述路徑上的代碼差異，發(fā)現(xiàn)后者在函數(shù) __add_to_page_cache_locked() 中，增加了以下代碼。mapping_gfp_constraint() 會將傳遞的 gfp_mask 與 inode->i_mapping 支持的 flags 進行按位與操作。根據(jù) vmcore 分析，確認 inode->i_mapping 是不支持 __GFP_NOFAIL 的，因此上層傳遞的 __GFP_NOFAIL 丟失了！
static int __add_to_page_cache_locked(struct page *page,
struct address_space *mapping,
pgoff_t offset, gfp_t gfp_mask,
void **shadowp)
{
...
gfp_mask = mapping_gfp_constraint(mapping, gfp_mask);
error = mem_cgroup_cache_charge(page, current->mm,
gfp_mask & GFP_RECLAIM_MASK);
...
在 Linux 的主線代碼歷史中并沒有在該位置添加過這行代碼。我們傾向于認為是 RedHat 的維護者在移植以下 patch 出錯了，mapping_gfp_constraint() 應(yīng)該針對部分操作作為 add_to_page_cache_lru() 的參數(shù)傳遞，而不是在隨后的 __add_to_page_cache_locked() 無條件執(zhí)行。
c20cd45eb017 mm: allow GFP_{FS,IO} for page_cache_read page cache allocation
c62d25556be6 mm, fs: introduce mapping_gfp_constraint()
6afdb859b710 mm: do not ignore mapping_gfp_mask in page cache allocation paths
diff --git a/mm/filemap.c b/mm/filemap.c
index 6ef3674c0763..1bb007624b53 100644
--- a/mm/filemap.c
+++ b/mm/filemap.c
@@ -1722,7 +1722,7 @@ static ssize_t do_generic_file_read(struct file *filp, loff_t *ppos,
goto out;
}
error = add_to_page_cache_lru(page, mapping, index,
- GFP_KERNEL & mapping_gfp_mask(mapping));
+ mapping_gfp_constraint(mapping, GFP_KERNEL));
if (error) {
page_cache_release(page);
if (error == -EEXIST) {
@@ -1824,7 +1824,7 @@ static int page_cache_read(struct file *file, pgoff_t offset)
return -ENOMEM;
ret = add_to_page_cache_lru(page, mapping, offset,
- GFP_KERNEL & mapping_gfp_mask(mapping));
+ mapping_gfp_constraint(mapping, GFP_KERNEL));
if (ret == 0)
ret = mapping->a_ops->readpage(file, page);
else if (ret == -EEXIST)
一個比較保險的修復方法是，在 __add_to_page_cache_locked() 中判斷上層是否傳入 __GFP_NOFAIL，在 mapping_gfp_constraint() 之后把 __GFP_NOFAIL 加回來。相比直接刪掉 mapping_gfp_constraint()，這種改法不需要修改所有 add_to_page_cache_lru() 的 caller，盡量保持原有的邏輯。
保證 grow_dev_page() 始終使用 __GFP_NOFAIL
在主線代碼中，我們發(fā)現(xiàn)下面三個 patch 加強了 grow_dev_page()，保證在所有場景中 grow_dev_page() 都使用 __GFP_NOFAIL。
bc48f001de12 buffer: eliminate the need to call free_more_memory() in getblk_slow()
94dc24c0c59a buffer: grow_dev_page() should use GFP_NOFAIL for all cases
640ab98fb362 buffer: have alloc_page_buffers() use __GFP_NOFAIL
commit 94dc24c0c59a224a093f110060d01c2c620f275a
Author: Jens Axboe
Date: Wed Sep 27 05:45:36 2017 -0600
buffer: grow_dev_page() should use __GFP_NOFAIL for all cases
We currently use it for find_or_create_page(), which means that it
cannot fail. Ensure we also pass in 'retry == true' to
alloc_page_buffers(), which also ensure that it cannot fail.
After this, there are no failure cases in grow_dev_page() that
occur because of a failed memory allocation.
最終修復方案
帶上上述兩方面修復，我們的復現(xiàn)腳本再也沒有復現(xiàn)該問題。目前我們已經(jīng)把該問題和可能的修復方式匯報給 Redhat（https://bugzilla.redhat.com/show_bug.cgi?id=1911392），希望后續(xù)能夠得到官方確認的最終修復方式。
總結(jié)
OOM Killer 是 Linux 提供的一項基本功能，然而這個場景相對比較罕見，難以保證各個模塊在內(nèi)存分配時能夠很好地處理。對于服務(wù)提供方，一方面，我們需要盡可能保證我們的服務(wù)不會出現(xiàn)內(nèi)存泄漏或者 OOM，這非常困難卻是值得投入的。另一方面，Linux Kernel 的 OOM 處理也飽受大家詬病，有許多開源項目幫助大家在用戶態(tài)做好 OOM 監(jiān)控，例如 facebookincubator/oomd（https://github.com/facebookincubator/oomd） 和 rfjakob/earlyoom（https://github.com/rfjakob/earlyoom），這樣就可以規(guī)避掉 Kernel OOM Killer 潛在的問題。
對文件系統(tǒng)和內(nèi)核感興趣的同學也歡迎加入我們。
作者介紹
Jiewei，SmartX 研發(fā)工程師。SmartX 擁有國內(nèi)最頂尖的分布式存儲和超融合架構(gòu)研發(fā)團隊，是國內(nèi)超融合領(lǐng)域的技術(shù)領(lǐng)導者。