Linux+squashfs+swapなし環境でOOM時にハングする問題

はじめに

Linuxでsquashfsを使っていてswapがない環境のときに、メモリ不足でOOM状態に陥ると高確率でシステム(kernel)がハング状態になってしまう、という問題の原因を掘り下げる記事になります。かなり限られた環境での問題なので、困ってる人は見かける(こことかこことかこことか)ものの、世の中の人はそれほど関心がなくて、なので問題が放置されているのかと思います。

環境の詳細やらはあえてぼかして書きます。記事では少し古いバージョンでのbacktraceを見たりしますが、コードを確認する限りでは現時点での最新のLinux-5.1.8でも起こるはずです。またコードはLinux-5.1.8を見て確認しています。

問題の起こす環境について

Linux

これはまぁいい。

squashfs

squashfsはRead Onlyで圧縮が使えるのが特徴のファイルシステム。メジャーと言うほどではないが、特殊用途の組込みシステムでは目にすることも多いのではないかと思う。そういう用途だけに、主にrootファイルシステムとして使い、読み書きするデータは別のファイルシステムにする、という構成になる。

ちなみに、この「圧縮が使える」の実装部分が今回の問題の発生箇所になっている。

swapがない環境

これも組込みシステムではよく目にする。最近はeMMCの容量も大きいのでswapを作ることもできなくはないが、どうせ読み書きが遅いし、頻繁に書くとフラッシュメモリ寿命問題も気にしないといけないので、だったらswapはなしでRAMを多めに積んどこう、となる。なおこの記事は、そんなRAMが十分でなかったときに起こる問題である。

OOM

みんな大好き大嫌いなOOM発動です。RAM足りなくなると何もできなくなるので、oom_adjを調整したり、panic_on_oomでOOM時にpanicさせたり、overcommit_memoryでオーバコミット設定変えたり、などなどを行ってOOMが発動しても影響がないように調整する。

OOMの起こし方は簡単で、malloc()でLinuxの仮想メモリ空間のメモリ確保をし続けるだけのプログラムのように、**malloc()とmemset()**を繰り返して、ユーザランドのresidentメモリをいっぱい使わせればよい。

問題発生時の状態を確認する

backtrace

今回はこちらの環境の詳細を明かさないため、代わりに、先に出した例(こことこことここと)からbacktraceを引っ張ってくることにして、

//lkml.iu.edu/hypermail/linux/kernel/1501.2/03899.html

[ 313.950118] [<c02d2014>] (__schedule+0x448/0x5cc) from [<c014e510>] (squashfs_cache_get+0x120/0x3ec)
[ 314.059660] [<c014e510>] (squashfs_cache_get+0x120/0x3ec) from [<c014fd1c>] (squashfs_readpage+0x748/0xa2c)
[ 314.176497] [<c014fd1c>] (squashfs_readpage+0x748/0xa2c) from [<c00b7be0>] (__do_page_cache_readahead+0x1ac/0x200)
[ 314.300621] [<c00b7be0>] (__do_page_cache_readahead+0x1ac/0x200) from [<c00b7e98>] (ra_submit+0x24/0x28)
[ 314.414325] [<c00b7e98>] (ra_submit+0x24/0x28) from [<c00b043c>] (filemap_fault+0x16c/0x3f0)
[ 314.515521] [<c00b043c>] (filemap_fault+0x16c/0x3f0) from [<c00c94e0>] (__do_fault+0xc0/0x570)
[ 314.618802] [<c00c94e0>] (__do_fault+0xc0/0x570) from [<c00cbdc4>] (handle_pte_fault+0x47c/0x1048)
[ 314.726250] [<c00cbdc4>] (handle_pte_fault+0x47c/0x1048) from [<c00cd928>] (handle_mm_fault+0x164/0x218)
[ 314.839959] [<c00cd928>] (handle_mm_fault+0x164/0x218) from [<c02d4878>] (do_page_fault.part.7+0x108/0x360)
[ 314.956788] [<c02d4878>] (do_page_fault.part.7+0x108/0x360) from [<c02d4afc>] (do_page_fault+0x2c/0x70)
[ 315.069442] [<c02d4afc>] (do_page_fault+0x2c/0x70) from [<c00084cc>] (do_PrefetchAbort+0x2c/0x90)
[ 315.175850] [<c00084cc>] (do_PrefetchAbort+0x2c/0x90) from [<c02d3674>] (ret_from_exception+0x0/0x10)

//www.spinics.net/lists/newbies/msg59591.html

[<c08394e4>] __schedule+0x2c8
[<c018df88>] squashfs_cache_get+0x108
[<c0191020>] squashfs_readpage_block+0x28
[<c018f648>] squashfs_readpage+0x624
[<c0090d4c>] __do_page_cache_readahead+0x228
[<c00882f4>] filemap_fault+0x1d4
[<c00a5f10>] __do_fault+0x34
[<c00a8ab0>] do_read_fault+0x19c
[<c00a9388>] handle_mm_fault+0x468
[<c00164b0>] do_page_fault+0x11c
[<c00084a4>] do_PrefetchAbort+0x34
[<c0011c1c>] ret_from_exception+0x0

//www.spinics.net/lists/newbies/msg59591.html

[ 240.800000] [<c03bd7ac>] (schedule+0x0/0x5fc) from [<c0194db8>](squashfs_cache_get+0x120/0x38c)
[ 240.812000] [<c0194c98>] (squashfs_cache_get+0x0/0x38c) from[<c0195050>] (squashfs_get_datablock+0x2c/0x34)
[ 240.820000] [<c0195024>] (squashfs_get_datablock+0x0/0x34) from[<c0195f78>] (squashfs_readpage+0x5c0/0x954)
[ 240.832000] [<c01959b8>] (squashfs_readpage+0x0/0x954) from[<c0117bdc>] (__do_page_cache_readahead+0x234/0x290)
[ 240.840000] [<c01179a8>] (__do_page_cache_readahead+0x0/0x290) from[<c0117c6c>] (ra_submit+0x34/0x3c)
[ 240.848000] [<c0117c38>] (ra_submit+0x0/0x3c) from [<c010f488>](filemap_fault+0x1ec/0x418)
[ 240.856000] [<c010f29c>] (filemap_fault+0x0/0x418) from[<c0126e58>] (__do_fault+0x60/0x490)
[ 240.868000] [<c0126df8>] (__do_fault+0x0/0x490) from [<c0128524>](handle_mm_fault+0x454/0x900)
[ 240.876000] [<c01280d0>] (handle_mm_fault+0x0/0x900) from[<c03c37e8>] (do_page_fault+0x19c/0x368)
[ 240.884000] [<c03c364c>] (do_page_fault+0x0/0x368) from[<c0038504>] (do_PrefetchAbort+0x44/0xa8)
[ 240.892000] [<c00384c0>] (do_PrefetchAbort+0x0/0xa8) from[<c03c19d0>] (ret_from_exception+0x0/0x10)

**squashfs_cache_get()からschedule()**を呼ぶあたりが怪しそうです。どうやら~~亭主を殺されたくない~~SIGKILLを受けても起きないから、のようです。...**do_PrefetchAbort()**を見て安心するのはARMユーザの証...

OOM-Killerが期待する動き

OOM Killerは、空気とかスコアとか読みながら、~~キミにきめた！~~プロセスに対し、SIGKILLをmm/oom_kill.cらへんで送ることで殺す。

シグナルを受けたプロセス(というかタスクというか)は、寝ていた場合は起こされ、そのままkernelから追い出される方向(システムコールがEINTRになる方向)へ動き、kernelから出る直前でシグナルハンドルを行い、SIGKILLなのでユーザランドでシグナルハンドリングされることなくそのまま終了する。終了すると、そのプロセスが使っていたメモリ(p->mm)が開放され、空きメモリが増え、OOM Killerを発動させた人(たいていはkmem_cacheやalloc_pages周辺を実行している)が無事メモリを確保できるようになる。

SIGKILLで起きない原因

**squashfs_cache_get()からschedule()**を呼ぶあたりでSIGKILLを受けても起きないのが原因のようなので、周辺のコードを確認する。kernel/fs/squashfs/cache.cより、

fs/squashfs/cache.c

/*
 * Look-up block in cache, and increment usage count.  If not in cache, read
 * and decompress it from disk.
 */
struct squashfs_cache_entry *squashfs_cache_get(struct super_block *sb,
	struct squashfs_cache *cache, u64 block, int length)
{
	int i, n;
	struct squashfs_cache_entry *entry;

	spin_lock(&cache->lock);

	while (1) {
		for (i = cache->curr_blk, n = 0; n < cache->entries; n++) {
			if (cache->entry[i].block == block) {
				cache->curr_blk = i;
				break;
			}
			i = (i + 1) % cache->entries;
		}

		if (n == cache->entries) {
			/*
			 * Block not in cache, if all cache entries are used
			 * go to sleep waiting for one to become available.
			 */
			if (cache->unused == 0) {
				cache->num_waiters++;
				spin_unlock(&cache->lock);
				wait_event(cache->wait_queue, cache->unused);
				spin_lock(&cache->lock);
				cache->num_waiters--;
				continue;
			}

			/*
			 * At least one unused cache entry.  A simple
			 * round-robin strategy is used to choose the entry to
			 * be evicted from the cache.
			 */
			i = cache->next_blk;
			for (n = 0; n < cache->entries; n++) {
				if (cache->entry[i].refcount == 0)
					break;
				i = (i + 1) % cache->entries;
			}

			cache->next_blk = (i + 1) % cache->entries;
			entry = &cache->entry[i];

			/*
			 * Initialise chosen cache entry, and fill it in from
			 * disk.
			 */
			cache->unused--;
			entry->block = block;
			entry->refcount = 1;
			entry->pending = 1;
			entry->num_waiters = 0;
			entry->error = 0;
			spin_unlock(&cache->lock);

			entry->length = squashfs_read_data(sb, block, length,
				&entry->next_index, entry->actor);

			spin_lock(&cache->lock);

			if (entry->length < 0)
				entry->error = entry->length;

			entry->pending = 0;

			/*
			 * While filling this entry one or more other processes
			 * have looked it up in the cache, and have slept
			 * waiting for it to become available.
			 */
			if (entry->num_waiters) {
				spin_unlock(&cache->lock);
				wake_up_all(&entry->wait_queue);
			} else
				spin_unlock(&cache->lock);

			goto out;
		}

		/*
		 * Block already in cache.  Increment refcount so it doesn't
		 * get reused until we're finished with it, if it was
		 * previously unused there's one less cache entry available
		 * for reuse.
		 */
		entry = &cache->entry[i];
		if (entry->refcount == 0)
			cache->unused--;
		entry->refcount++;

		/*
		 * If the entry is currently being filled in by another process
		 * go to sleep waiting for it to become available.
		 */
		if (entry->pending) {
			entry->num_waiters++;
			spin_unlock(&cache->lock);
			wait_event(entry->wait_queue, !entry->pending);
		} else
			spin_unlock(&cache->lock);

		goto out;
	}

out:
	TRACE("Got %s %d, start block %lld, refcount %d, error %d\n",
		cache->name, i, entry->block, entry->refcount, entry->error);

	if (entry->error)
		ERROR("Unable to read %s cache entry [%llx]\n", cache->name,
							block);
	return entry;
}

うん、もろに**wait_event()が原因ですね。シグナルを受けたときに起きるためには、TASK_UNINTERRUPTIBLEになるwait_event()ではなくて、TASK_INTERRUPTIBLEになるwait_event_interruptible()**を使うのが正解です。wait_event系には、(あとでここに列挙)があって、...と思ったら知らん間にめっちゃたくさんあるやんけ...kernel/include/linux/wait.hあたりより、

• wait_event()
• wait_event_freezable()
• wait_event_timeout()
• wait_event_freezable_timeout()
• wait_event_exclusive_cmd()
• wait_event_cmd()
• wait_event_interruptible()
• wait_event_interruptible_timeout()
• wait_event_hrtimeout()
• wait_event_interruptible_hrtimeout()
• wait_event_interruptible_exclusive()
• wait_event_killable_exclusive()
• wait_event_freezable_exclusive()
• wait_event_idle()
• wait_event_idle_exclusive()
• wait_event_idle_timeout()
• wait_event_idle_exclusive_timeout()
• wait_event_interruptible_locked()
• wait_event_interruptible_locked_irq()
• wait_event_interruptible_exclusive_locked()
• wait_event_interruptible_exclusive_locked_irq()
• wait_event_killable()
• wait_event_killable_timeout()
• wait_event_lock_irq_cmd()
• wait_event_lock_irq()
• wait_event_interruptible_lock_irq_cmd()
• wait_event_interruptible_lock_irq()
• wait_event_interruptible_lock_irq_timeout()
• wait_event_lock_irq_timeout()

見つけてしまったからには仕方ない、少し解説を入れると、

• freezableがつくと、寝るときにFREEEZEしてもよい。ついていないとFREEEZEしない。FREEEZEについてはこのへんでも。
• timeoutがつくと、timeoutで起きる。ついていないとtimeoutしない。
• hrtimeoutがつくと、timeoutをハイレゾタイマーで指定できる。
• exclusiveがつくと、wake_up()で起こすときのタスクの数を厳密に管理する(WQ_FLAG_EXCLUSIVE)
• interruptibleがつくと、シグナルを受けたときに起きる、ついていないと起きない。
• killableがつくと、killする系のシグナルのときだけシグナル抜けする、ついていないと起きない。
• idleがつくと、UNINTERRUPTIBLE状態のときにloadavg計算に計上しないようにする、ついていないとloadavg計上する。
• lockedがつくと、wait queueのlockを取ったまま呼ぶという使い方をする。
• irqがつくと、lockはspin_lock()として扱う。
• cmdがつくと、lock開放してから寝るまでの間にcmd;を実行する

くらいか？正確に理解しようとするとややこしい。

ZOMBIEとの違い

ここまでの話を読んだあと、これはZOMBIEのことだと勘違いする人がいるかも知れないので、念のため。

ZOMBIEは、プロセスが終了した後から、プロセスの親にwait()されるまでの間の状態のことなので、上記の話(まだ終了していない状態)とは異なる。ZOMBIE状態では、mmやfdはすでに開放されているため、これが残ったからと言ってOOMなどのリソース不足状態にはなりにくい。いや、struct task_struct類が残るので、メモリ少しとPID数とあたりが残ってしまうかな？いずれにしても別の話だということで。

修正方法

先の通り**wait_event()が原因なのでこれをwait_event_interruptible()**に置き換える。とはいっても、正常に起こされた場合と、シグナルで起こされた場合とで処理を分岐させる必要があり、またlockや返り値に気をつける必要があるので、少し小細工が必要になる。というわけで、こんなパッチを書いてみた(Linux-5.1.8向け)

linux_squashfs_wait_interrupt.diff

diff --git a/fs/squashfs/cache.c b/fs/squashfs/cache.c
index 0839efa720b3..ae4a67459ba3 100644
--- a/fs/squashfs/cache.c
+++ b/fs/squashfs/cache.c
@@ -52,12 +52,26 @@
 #include <linux/spinlock.h>
 #include <linux/wait.h>
 #include <linux/pagemap.h>
+#include <linux/sched/signal.h>

 #include "squashfs_fs.h"
 #include "squashfs_fs_sb.h"
 #include "squashfs.h"
 #include "page_actor.h"

+#define SQUASHFS_FIX_INTERRUPT (1)
+#if defined(SQUASHFS_FIX_INTERRUPT)
+// In case OOM killer is trigerred.
+// SIGKILL may be sent to the current task.
+// So we need to handle it.
+//
+// squashfs_cache_get() is expecting to get a valid entry.
+// So here I prepare null object pattern of entry to ret error.
+static struct squashfs_cache_entry squashfs_signal_interrupted_error_entry = {
+    .error = -ENOMEM,
+};
+#endif
+
 /*
  * Look-up block in cache, and increment usage count.  If not in cache, read
  * and decompress it from disk.
@@ -68,6 +82,15 @@ struct squashfs_cache_entry *squashfs_cache_get(struct super_block *sb,
        int i, n;
        struct squashfs_cache_entry *entry;

+#if defined(SQUASHFS_FIX_INTERRUPT)
+    int wait_interrupted;
+    if (fatal_signal_pending(current)) {
+        entry = &squashfs_signal_interrupted_error_entry;
+               ERROR("%d has fatal signal. interrupted\n", current->pid);
+        goto out;
+    }
+#endif
+
        spin_lock(&cache->lock);

        while (1) {
@@ -87,9 +110,24 @@ struct squashfs_cache_entry *squashfs_cache_get(struct super_block *sb,
                        if (cache->unused == 0) {
                                cache->num_waiters++;
                                spin_unlock(&cache->lock);
+#if defined(SQUASHFS_FIX_INTERRUPT)
+                               wait_interrupted = wait_event_interruptible(cache->wait_queue, cache->unused);
+#else
                                wait_event(cache->wait_queue, cache->unused);
+#endif
                                spin_lock(&cache->lock);
                                cache->num_waiters--;
+#if defined(SQUASHFS_FIX_INTERRUPT)
+                if (wait_interrupted != 0) {
+                    if (fatal_signal_pending(current)) {
+                        spin_unlock(&cache->lock);
+                        entry = &squashfs_signal_interrupted_error_entry;
+                        ERROR("%d has fatal signal. interrupted\n", current->pid);
+                        goto out;
+                    }
+                }
+#endif
+
                                continue;
                        }

@@ -187,6 +225,13 @@ void squashfs_cache_put(struct squashfs_cache_entry *entry)
 {
        struct squashfs_cache *cache = entry->cache;

+#if defined(SQUASHFS_FIX_INTERRUPT)
+    if (entry == &squashfs_signal_interrupted_error_entry) {
+        // This is null object. Nothing to do.
+        return;
+    }
+#endif
+
        spin_lock(&cache->lock);
        entry->refcount--;
        if (entry->refcount == 0) {

エラーを返すことを想定していないコードなのでエラーを表すNULLオブジェクト(squashfs_signal_interrupted_error_entry)を使っている、とかいう話はこんな怪しいパッチを拾って適用しようとしている人に向けてあえて言う必要もないのかな。

ただこれで動かしたところ、SIGKILLではなくてSIGBUSで死ぬことが多い。おそらくSetPageError()を呼んだりVM_FAULT_OOMを返していなかったりするのが影響してるんだろうけど、そこまで手をかけてられなかったので、あとは誰か任せた。

squashfsの該当箇所がやっている内容

**squashfs_cache_get()**は、squashfsの圧縮されたデータを展開してreadしたい人に渡すという処理の一環で、その処理用の一時バッファを確保している箇所となっている。複数タスクから同時に呼ばれたり、ディレクトリウォークで親から子にメタデータと実体を順に読んだり、といった使われ方をするので、ある程度のサイズのキャッシュは必要だけど、だからといって取りすぎるのも良くなく、そんな一時バッファを管理している。バッファキャッシュに連動した動きをするけどバッファキャッシュとは別物になっている。

noswapの場合、RAMの残りが厳しくなるとバッファキャッシュがどんどん追い出される。だけどプログラムを動かすためには該当プログラムの.textなどはRAMに置く必要がある。結果、いわゆるスラッシング状態になる。このとき、OOM-Killerに選ばれたタスクがたまたまちょうどsquashfsからの読み込み中だった場合に、今回のようなハング状態に陥る。「動いている」プログラムほどバッファキャッシュが追い出されてもすぐに読み込み直しが走りやすく、また「動いている」プログラムほどたいていはRAMもたくさん使っていることが多いため、条件さえ整えばこの問題に高頻度で直面することになる。

あとがき

というわけで、マイナーな問題にフォーカスを当てて、何がどうまずいのかを周辺の解説を添えながら記事にしてみた。「んなマイナーな環境の問題なんて興味ねーよ」「OOM-Killerが動いたんだからその後のことなんて知ったこっちゃねぇ」「お前はLKMLへのパッチの送り方も知らないのか」という声が聞こえてきそうですが、記事を書くことなんてただの自己満足なので、そっと読み飛ばしてページを閉じてくださいな。

参考リンク

OOMはみんな大好き大嫌いなので、挙動を解説してくれる記事がたくさん見つかり非常に助かる。

• Linux OOM Killerについて
• malloc()でLinuxの仮想メモリ空間のメモリ確保をし続けるだけのプログラム - Qiita
• LinuxにおけるOOM発生時の挙動 - Qiita
• About vm.overcommit_memory - Qiita
• Linux Power Managementのカーネル実装(freeze)を読む(その1) - Qiita
• Linux Power Managementのカーネル実装(freeze)を読む(その2) - Qiita
• Linux(x86-32bit)のページフォルトハンドラを読んでみる(その4) - Qiita
• TASK_KILLABLE - [LWN.net]
• Linux Kernel: TASK_IDLE を調べる - hibomaの日記
• Linux memo 2019/03/15 - (自サイトの宣伝)