0
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

PCが完全フリーズ→強制電源断。ログを掘ったら「安全網が3つとも黙っていた」

0
Last updated at Posted at 2026-09-01

はじめに

ある夜、ノートPCが完全に固まった。

カーソルは動かない。仕方なく電源ボタンを長押しして、強制的に電源を落とした。

翌朝、journalctl と sysstat(sar) のログを掘って原因を特定した記録である。

この記事で分かること

  • 強制電源断だったことをログで確定する方法
  • 「OOM Killer が出ていない」が何の証拠にもならない理由
  • sar が記録している PSI で、詰まっていた軸を特定する方法

検証環境は以下のとおりである。

項目 値
OS Ubuntu(カーネル 6.17.0-35-generic)
CPU 4コア
RAM 16GB
ストレージ SATA SSD 1TB
systemd 255
sysstat 12.6.1
スワップ ファイル4本 計32GB(4 + 4 + 8 + 16GB)
vm.swappiness 20

👉 結論から書くと、詰まっていたのは I/O と CPU で、そこには見張り番がいなかった。


前提:フリーズ中のログは残らない

フリーズ中はディスクに書き込めない。だから「その瞬間のログ」は原理的に存在しない。

事後解析は、直接の証拠ではなく間接証拠を積む作業になる。「何が起きたか」を直接見ることはできないので、「何が起きなかったか」を1つずつ確定していくしかない。

今回使った道具は3つである。

  • journalctl … 何が起きなかったかを確定する
  • sysstat(sar) … 固まる前の状態を10分刻みで復元する
  • oomctl … 安全網がどう構えていたかを確認する

👉 sysstat が入っていないと、後半の解析は再現できない。入れていない場合は sudo apt install sysstat を実行し、/etc/default/sysstat の ENABLED="true" を確認する。詳細は後半の対策の章で扱う。


Step 0: まず「強制電源断だった」ことを確定する

最初に打つのは journalctl --list-boots である。

なぜ打つか。ブートの境界と、ログが途切れた時刻を確定するためである。ここが決まらないと、以降のすべての切り分けの起点が定まらない。

$ journalctl --list-boots
...
 -1 <BOOT_ID_A> Sat 2026-08-29 18:59:48 Wed 2026-09-02 00:50:08
  0 <BOOT_ID_B> Wed 2026-09-02 01:24:17 Wed 2026-09-02 01:26:56

読み取れることは次の3点である。

  • 前回ブートのログは 00:50:08 で途切れている
  • 次のブートは 01:24:17 に始まっている
  • 正常なシャットダウンなら Stopping... や Reached target Shutdown のログが並ぶはずだが、一切ない

次に物証を確認する。なぜ打つか。「途切れている」だけでは電源断の証明にならないからである。ログが途切れる原因はフリーズ以外にもありうる。

$ journalctl -b 0 | grep -iE "dirty bit|not properly|unclean"
systemd-fsck[823]: Dirty bit is set. Fs was not properly unmounted and some data may be corrupt.
systemd-fsck[823]:  Automatically removing dirty bit.
kernel: exFAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
systemd[1]: kerneloops.service: This usually indicates unclean termination of a previous run, or service implementation deficiencies.

FAT の EFI パーティションと exFAT の SD カードの両方が「正常にアンマウントされなかった」と申告している。これで強制電源断は確定した。

❌ 「ext4 のルートに fsck の警告が出ていない=正常に終了した」ではない。
ext4 はジャーナルを黙って回復するので、強制電源断でも何も言わないことがある。上の警告が出たのは FAT の EFI パーティションと exFAT の SD カードの側であり、ext4 のルートパーティションは沈黙していた。


仮説①:カーネルパニックやハード障害か

強制電源断は確定した。次に切り分けるべきは、カーネルが死んだのか、それともユーザー空間が詰まっただけなのかである。ここで以降の調べ方が変わる。

journalctl -b -1 | grep -iE "BUG:|call trace|soft lockup|hard LOCKUP|hung_task|blocked for more than"

なぜ打つか。カーネルパニックやハングタスクが起きていれば、ここに痕跡が残るからである。前回ブート(-b -1)のログを対象に、複数の仮説を一度に潰していく。

結果は以下のとおりである。

仮説 確認コマンド 結果
カーネルパニック journalctl -b -1 | grep -E "BUG:|call trace|soft lockup" 0件
ハングタスク journalctl -b -1 | grep -E "hung_task|blocked for more than" 0件
パニック痕跡の永続化 sudo ls /sys/fs/pstore/ 空
ストレージ障害 journalctl -b 0 -p warning | grep -iE "I/O error|ext4.*error" 0件
熱暴走 journalctl -b -1 | grep -iE "thermal|critical temp" 0件

全部シロだった。カーネル自体がクラッシュした形跡はどこにもない。

-p err は「赤いものを全部読む」道具ではない

唯一 -p err(error 以上の重大度)で出てきたのが、以下のログである。

$ journalctl -b -1 -p err | tail -5
kernel: rtw88_8822be 0000:02:00.0: failed to send h2c command
kernel: rtw88_8822be 0000:02:00.0: failed to send h2c command
kernel: rtw88_8822be 0000:02:00.0: failed to send h2c command

👉 これは無線ドライバのエラーである。数時間にわたり断続的に出ており、フリーズ直前に増えてもいない。よって無関係と判断した。

👉 -p err で見るべきは「赤い行があるか」ではなく「フリーズ直前に増えたか」である。
常に出ているエラーは、その日の犯人ではない。


仮説②:OOM Killer に殺されたのか

カーネルは生きていた。となると次に疑うのは、メモリ不足で何かが強制終了させられ、それが道連れになった可能性である。

$ journalctl -b -1 | grep -iE "out of memory|oom-kill|oom_reaper" | wc -l
0

なぜ打つか。メモリ不足で何かが殺され、それが道連れになった可能性を潰すためである。

0件。メモリ不足ではない——と、このときは思った。


❌「OOM Killer が出ていない」=「メモリは足りていた」ではない

ここが記事の転換点である。ここで「OOM Killer が出ていないのでメモリは関係なかった」と結論づけてしまうと、判断を誤る。

OOM Killer の発動条件を確認する。

  • OOM Killer の発動条件は「ページの回収もスワップアウトもできなくなったとき」である
  • この機体は RAM 16GB に対しスワップを 32GB 積んでいた
  • 実測でスワップ使用率は 17〜20%。つまり逃がす先が 25GB 以上残っていた
  • カーネルから見て「メモリを確保できない」状況は、最後まで発生していない

👉 OOM Killer は「マシンが使い物になるか」ではなく「メモリを確保できるか」で判断する。
体感速度は判断材料に入っていない。
だから「固まったのに OOM Killer が出ない」は矛盾ではなく、仕様どおりである。

❌ 「oom-kill が無い」は「メモリは足りていた」の証拠にならない。
何の証拠にもならない。 メモリが足りていたかどうかは、別の指標で測る必要がある。

では何で測るのか。sar が10分ごとに記録していた。


sar で「固まる前」を復元する

sysstat は既定で10分ごとにシステム状態をスナップショットしている。保存先は /var/log/sysstat/saNN(NN は日)である。フリーズ中は書けないが、フリーズ「前」は残っている。

# 当日(2日)のファイルを指定して読む
sar -u -f /var/log/sysstat/sa02

まず CPU:sar -u

なぜ打つか。CPU が計算で詰まったのか、I/O 待ちで詰まったのかを分けるためである。

00:00:05        CPU     %user     %nice   %system   %iowait    %steal     %idle
00:10:00        all     44.09      0.01      5.98     48.99      0.00      0.94
00:20:06        all     51.63      0.00      8.85     32.61      0.00      6.90
00:30:09        all     37.59      0.00      4.98     50.87      0.00      6.55
00:40:16        all     80.87      0.01     10.05      7.90      0.00      1.17

読み取り。

  • %idle が 0.94% と 1.17%。CPU に空きがない
  • 前半(00:00〜00:30)は %iowait が 33〜51%。I/O 待ちで詰まっている
  • 後半(00:30〜00:40)は %user が 80.87% に振れ、%iowait は 7.90% に下がる。CPU 自体で詰まっている

👉 前半と後半でボトルネックが移っている。 単一の犯人を探す姿勢だと見落とす。

メモリを見る:sar -r / sar -S

なぜ打つか。メモリが枯渇していたかを確認するためである。

sar -r -f /var/log/sysstat/sa02
sar -S -f /var/log/sysstat/sa02
00:00:05    kbmemfree   kbavail kbmemused  %memused   kbcommit   %commit
00:10:00      6197800   9293608   5552668     34.08   42469984     85.20
00:20:06      7284064  11477288   3488412     21.41   34324464     68.86
00:30:09      3988784   8341332   6551468     40.21   39143796     78.53
00:40:16      6097644   9147480   5550332     34.07   37124836     74.48
00:00:05    kbswpfree kbswpused  %swpused
00:10:00     26887320   6667096     19.87
00:20:06     27080408   6474008     19.29
00:30:09     27202264   6352152     18.93
00:40:16     27773212   5781204     17.23

読み取り。

  • 空きメモリ(kbavail)は常に 8〜11GB あった
  • %memused は最大 40.21%
  • スワップ使用は 6.6GB → 5.8GB と減っている(スワップ「イン」が優勢)

👉 ここだけ見ると「メモリは余裕」に見える。この見方はおおむね正しい方向を向いている。 ただし「その余裕を保つためにカーネルがどれだけ働いていたか」は、この表からは読み取れない。

使用量ではなく「回収レート」を見る:sar -B / sar -W

この節が本章の山場である。

なぜ打つか。%memused が横ばいでも、それを維持するためにカーネルが働いているかは別問題だからである。

sar -B -f /var/log/sysstat/sa02   # ページング・リクレイム
sar -W -f /var/log/sysstat/sa02   # スワップイン/アウト
00:00:05     pgpgin/s pgpgout/s   fault/s  majflt/s  pgfree/s pgscank/s pgscand/s pgsteal/s    %vmeff
00:10:00      2333.16   1028.78  39656.00    112.04  40045.51      0.00      0.00      0.00      0.00
00:20:06      2039.37   1454.55  46226.54     90.32  47377.80     40.33     11.12     99.79    193.95
00:30:09      1149.30    600.65  21473.89     42.73  21347.24    143.56     56.17    396.20    198.37
00:40:16      3708.64   2484.88  42363.49    125.47  46938.10   1983.72    162.79   3254.62    151.62
            pswpin/s pswpout/s
00:10:00      158.65      0.00
00:20:06       35.92      0.55
00:30:09       63.02      0.25
00:40:16      139.07    257.05

読み取り。

指標 推移 意味
pgsteal/s 0 → 99.79 → 396.20 → 3254.62 回収したページ数。32倍に急増
pgscank/s 0 → 40.33 → 143.56 → 1983.72 回収候補を探すスキャン量
pswpout/s 0 → 0.55 → 0.25 → 257.05 スワップ「アウト」が始まった

👉 %memused は横ばいなのに、それを維持するためのカーネルの労力が指数的に増えていた。
リクレイム(=ページの回収)の負荷が悪化していたのは事実であり、マシンが良くない方向に向かっていた兆候ではある。だがこれ自体は、まだ「メモリで詰まった」ことを意味しない。回収がタスクを実際に止めたかどうかは、次章の PSI で確認する。

この数字が異常なのかどうかは、比較対象がないと判断できない。同じ機体の前日23時台を見る。

sar -B -f /var/log/sysstat/sa01 | tail -6
sar -W -f /var/log/sysstat/sa01 | tail -6

tail で切っているのでヘッダ行は出ない。列の並びは上のふたつの表と同じである。

23:10:16        33.97    121.58   1646.17      1.00   1748.24      0.00      0.00      0.00      0.00
23:20:16         2.31     84.68   1519.58      0.09   1596.05      0.00      0.00      0.00      0.00
23:30:09         1.28     95.98   1593.30      0.05   1669.76      0.00      0.00      0.00      0.00
23:40:22       190.18    172.03   3170.67      4.16   3366.50      0.00      0.00      0.00      0.00
23:50:09        82.51    161.55   5757.52      0.95   6335.82      0.00      0.00      0.00      0.00
23:10:16         0.67      0.00
23:20:16         0.05      0.00
23:30:09         0.03      0.00
23:40:22        30.07      0.00
23:50:09         0.62      0.00

pgscank/s・pgscand/s・pgsteal/s・pswpout/s がすべて 0.00 である。前日はリクレイムがまったく起きていない。当日の 3254.62 は、この機体の平常値からの逸脱として確定できる。

👉 ついでに fault/s も見ておくとよい。前日は 1,519〜5,757 だが、当日は 21,473〜46,226 と一桁多い。後述するプロセス生成レートの差(前日 80/秒 → 当日 87〜105/秒)と符合する。

負荷の中身:sar -q / sar -w / sar -b

なぜ打つか。何がマシンを埋めていたかの当たりをつけるためである。

00:00:05      runq-sz  plist-sz   ldavg-1   ldavg-5  ldavg-15   blocked
00:10:00            6      2365      7.17      4.30      2.86         8
00:20:06            0      2010      0.71      4.63      4.43         8
00:30:09           20      2251     13.12      7.00      5.02         8
00:40:16           10      2054      4.63     11.99      9.65         6
00:00:05       proc/s   cswch/s
00:10:00        87.33  10940.09
00:20:06       105.25  14777.25
00:30:09        90.75   9366.28
00:40:16        96.62  14446.05

読み取り。

  • ldavg-1 が最大 13.12。4コア機なのでコア数の3倍超
  • proc/s が 87〜105 プロセス/秒。これが1時間続いた
    • 平常時に同じ機体で測ると 15 プロセス/秒 だった
  • 動いていたのはブラウザ自動テスト、dev server、エディタ複数

さらに I/O の量を見る。

00:00:05          tps      rtps      wtps   bread/s   bwrtn/s
00:10:00       236.15    219.94     16.21   4636.31   2057.57
00:20:06       133.13    104.74     28.39   4078.73   2909.10
00:30:09       110.81     99.11     11.71   2298.61   1201.29
00:40:16       272.41    217.61     54.80   7406.68   4969.75

👉 bread/s は 2298〜7406 blocks/s、つまり概ね 1〜4 MB/s。
SATA SSD にとっては何でもない量である。帯域は余っていた。
それでも詰まったのはなぜか——次章の PSI がそれに答える。


決定打:sar -q ALL は PSI を持っている

前章までで、CPU・メモリ・I/O のそれぞれに「怪しい動き」は見つかった。だが「結局どれが主犯か」はまだ決めきれていない。ここで使うのが PSI(Pressure Stall Information) である。

PSI はカーネルが /proc/pressure/cpu / /proc/pressure/io / /proc/pressure/memory として公開している指標で、「リソースが足りないせいでタスクが実際に止まっていた時間の割合」を直接教えてくれる。CPU使用率や空きメモリのような間接指標と違い、PSI は「詰まっていたかどうか」そのものを数値化している。

そして sysstat 12.6.1 には、この PSI を sar の履歴として記録する機能がある。

sar -q ALL -f /var/log/sysstat/sa02

列の読み方を間違えると全部が崩れる。

PSI の列には some(%s*)と full(%f*)の2種類がある。

  • %s* = 一部のタスクが停止していた割合
  • %f* = すべてのタスクが停止していた割合

そして同じ %sio 系の中にも4本の列がある。

%sio-10  %sio-60  %sio-300  %sio
  • %sio-10 / %sio-60 / %sio-300 は、そのサンプリング時点でカーネルが保持していた avg10 / avg60 / avg300(直近10秒・60秒・300秒の移動平均)の瞬間値である。
  • 接尾辞のない %sio こそが、そのサンプリング区間(今回は10分間)全体の平均値である。記事で読むべき数値はこちらである。

つまり -10 -60 -300 は「その瞬間、直近何秒がどうだったか」を表すスナップショットにすぎず、区間全体の傾向を知りたいなら無印の列を見る。この取り違えは致命的なので、以下の表もすべて無印の列(%scpu / %sio / %fio / %smem / %fmem)を中心に読んでいく。

まず CPU。

            %scpu-10  %scpu-60 %scpu-300     %scpu
00:10:00       50.40     39.91     20.74     15.00
00:20:06        0.98      2.83     20.13     30.12
00:30:09       75.07     67.22     33.86     24.94
00:40:16       18.25     27.54     54.24     65.04

sar -q ALL の CPU 出力には %fcpu(full)列が無い。/proc/pressure/cpu 自体には full 行が存在するが、システム全体では常にほぼ0であり(全タスクが同時に停止すればCPUはアイドルになるため)、sar もこれを列として記録していない。よってこの章の CPU 表は %s* のみを扱う。%scpu は 15.00 → 30.12 → 24.94 → 65.04 と、末期に向かって悪化している。

次に I/O。

             %sio-10   %sio-60  %sio-300      %sio   %fio-10   %fio-60  %fio-300      %fio
00:10:00       73.42     82.96     92.30     94.92      9.27     18.85     40.18     49.08
00:20:06       82.56     83.31     83.68     81.64     76.00     72.13     45.87     34.34
00:30:09       65.39     67.56     80.21     83.99      0.00      5.20     38.51     52.67
00:40:16       75.69     71.69     67.40     65.12     31.27     30.47     16.21      8.04

この表の 00:30:09 の行を見ると分かりやすい。%fio-10 が 0.00、%fio-60 も 5.20 と、サンプリングした瞬間だけを見れば「落ち着いている」ように見える。しかし無印の %fio は 52.67——その10分間全体で均せば、半分以上の時間、全タスクが停止していたことになる。瞬間値はたまたま鎮静化のタイミングを捉えただけであり、区間平均である 52.67 の方がこの10分間の実態を表している。

最後にメモリ。

            %smem-10  %smem-60 %smem-300     %smem  %fmem-10  %fmem-60 %fmem-300     %fmem
00:10:00        0.01      0.04      0.13      0.18      0.00      0.00      0.06      0.11
00:20:06        0.00      0.00      0.00      0.03      0.00      0.00      0.00      0.01
00:30:09        0.43      0.34      0.11      0.16      0.09      0.09      0.01      0.09
00:40:16        0.06      0.29      0.58      0.83      0.05      0.19      0.14      0.28

3つを並べる。

軸 full(全タスク停止)の区間平均 判定
メモリ 0.11 / 0.01 / 0.09 / 0.28 % ほぼゼロ
I/O 49.08 / 34.34 / 52.67 / 8.04 % 深刻
CPU %scpu 15.00 / 30.12 / 24.94 / 65.04 % 末期に深刻

👉 %fio = 49.08 の意味 = その10分間のうち約半分、すべてのタスクが I/O 待ちで停止していた。
これが体感の「フリーズ」の正体である。

メモリ圧は最大 0.28%。メモリは、詰まっていなかった。

前章のリクレイム急増(pgsteal/s が32倍)はここでどう決着するか。答えはこの %fmem に出ている。カーネルは苦労していたが、苦労は成功していた。メモリは「悪化しつつあったが、まだ詰まってはいなかった」——リクレイムの負荷そのものはメモリ待ちの停止には変換されなかった。ただしタダでは済んでいない。リクレイムに伴う pswpout/s(00:40:16 時点で 257.05)はディスクへの書き込みであり、これは次に見る I/O の軸に上乗せされていた分でもある。

前章では bread/s が概ね 1〜4 MB/s しか出ておらず、「帯域は余っていた」ことを確認した。にもかかわらず I/O の full 圧力が最大で区間の半分に達していたということは、話が「帯域」の問題ではないと分かる。

👉 ここで効いてくるのが PSI full の性質である。full はスループットではなくタスクが実際に止まっていた時間を測る指標であり、動いたデータ量が少なくても、実行したいタスク全員が待たされていれば値は上がる。proc/s が約96(=fork/exec の連発)だったことを踏まえると、短命なプロセスが次々に生成され、そのたびに exec 時の同期的な小さい読み込みが発生していたと考えられる。小さな同期読み込みが数多く積み重なれば、合計の転送量や IOPS が低くても、待ち時間の合計は長くなりうる。

ただし正直に言う。tps(110〜272)も帯域(1〜4 MB/s)も、この SATA SSD にとって絶対値としては大きくない。手元のデータが示しているのは「I/O 待ちで全員が止まっていたこと」までであり、「なぜデバイスがそこまで応答を遅らせていたか」までは説明できていない。そこは分からないままにしておく。

正直に書く:最後の10分のデータは無い

sar のサンプリングは10分間隔であり、sa02 に残っている最後のレコードは 00:40:16 である。フリーズから強制電源断までの間には、まだ続きがあったはずなのに、そこから先のデータは存在しない。

一方で、journalctl -b -1 を見ると sysstat-collect.service は次のように正常終了したログが残っている。

$ journalctl -b -1 | tail -3
systemd[1]: Starting sysstat-collect.service - system activity accounting tool...
systemd[1]: sysstat-collect.service: Deactivated successfully.
systemd[1]: Finished sysstat-collect.service - system activity accounting tool.

サービスは 00:50:08 に正常終了したと記録されているにもかかわらず、sa02 には 00:50 のレコードが存在しない。

👉 journald は書き込みを同期的に行う一方、sadc が書いたはずのデータはページキャッシュに留まったまま電源が切れた——と考えると辻褄は合う。ただしこれは推測であり、確認できた事実ではない。

👉 事後解析には必ずこの死角がある。
手元にある最後のサンプルは「悪化の途中経過」であって「臨終の瞬間」ではない。
だから本記事も、フリーズの最後の10分間に何が起きたかまでは断定しない。


なぜ安全網は3つとも黙っていたのか

前章までで実測は出そろった。メモリ圧はほぼ0(%smem 最大0.83%)、I/O 圧は最大52.67%まで悪化していた。Linux には「メモリが厳しくなったら助ける」仕組みが複数積まれている。カーネルの OOM Killer、そして Ubuntu が標準で動かしている systemd-oomd(スワップ監視とメモリ圧監視の2系統)である。この3つがなぜ揃って沈黙していたのかを、ひとつずつ確認する。

①カーネル OOM Killer

発動条件はすでに前章「❌『OOM Killer が出ていない』=『メモリは足りていた』ではない」で確認済みなので、ここでは結論だけ振り返る。

  • 発動条件はページの回収もスワップアウトもできなくなったとき
  • スワップ32GB中17〜20%しか使っておらず、逃がす先が25GB以上残っていた
  • → カーネルから見て「メモリ不足」ではないため、発動しない

②systemd-oomd のスワップ監視

Ubuntu には systemd-oomd がいる。OOM Killer より先にメモリ危機を検知して cgroup ごと殺すはずの見張り番である。これがなぜ黙っていたのかを確認する。

$ oomctl
Dry Run: no
Swap Used Limit: 90.00%
Default Memory Pressure Limit: 60.00%
Default Memory Pressure Duration: 20s
Swap Monitored CGroups:
Memory Pressure Monitored CGroups:
	Path: /user.slice/user-1000.slice/user@1000.service
		Memory Pressure Limit: 50.00%
  • Swap Monitored CGroups: が空。 Ubuntu の既定では、スワップ基準の kill が誰にも設定されていない
  • 仮に有効でも Swap Used Limit = 90.00% に対し、実測は 19.87%。届かない

③systemd-oomd のメモリ圧監視

  • user@1000.service には Memory Pressure Limit: 50.00% が設定されている(武装はしている)
  • 発動には、メモリ PSI が 50% を DefaultMemoryPressureDurationSec の間超え続ける必要がある
    • man 5 oomd.conf の既定は 30秒
    • この環境では drop-in で 20秒に上書きされていた
systemd-analyze cat-config systemd/oomd.conf | grep -E "SwapUsedLimit|DefaultMemoryPressure"
  • 実測のメモリ圧 %smem は最大 0.83%。50% には遠く及ばない
軸 実測(最悪値) 見張り番 結果
メモリ 圧 0.83%(%smem) OOM Killer / systemd-oomd 閾値未達で不発
I/O 全停止 52.67%(%fio) なし そもそも見ていない
CPU %idle 0.94% / load 13.12 なし そもそも見ていない

👉 Linux の既定の安全網は、メモリしか見ていない。
I/O と CPU で詰まったマシンは、誰にも助けられずに固まり続ける。
3つとも「正常に動作した上で」黙っていた。バグではない。死角である。


スワップを増やすほど、OOM Killer は遠のく

この機体は RAM 16GB に対し、スワップ 32GB(2倍)を積んでいた。

  • スワップが大きいほどカーネルは「まだ逃がせる」と判断する → OOM Killer が遠のく
  • その間、マシンは殺されずに劣化し続ける
  • systemd-oomd 側の SwapUsedLimit=90% は、この議論には関係しない。②で見たとおり Swap Monitored CGroups が空で、スワップのサイズによらず最初から誰も監視していなかったからである。ここで遠のいていたのは、あくまでカーネル OOM Killer の側の話である

❌ 「フリーズするからスワップを増やそう」は、逆効果になりうる。
スワップは「落ちない」ためのものであって、「速い」ためのものではない。
増やすほど、落ちる代わりに遅いまま生き続ける時間が延びる。
ただし今回に限って言えば、実測のスワップ使用量は約6GB、%memused も34〜40%にとどまっていた。仮に半分にしていたとしても、OOM Killer の発動ラインには程遠かったはずである。

👉 とはいえ「スワップを全部消せ」ではない。休止状態には要るし、
急なメモリ要求を吸収する役目もある。
問題は量で、RAM を超える大きさのスワップは、カーネル OOM Killer が働き始めるタイミングを遠ざける副作用がある、という話である。


犯人ではなかったもの

I/O と CPU に「詰まった軸」が判明した後、もう一つやることがある。最初に疑ったが違ったものを、なぜ違うと言えるのかまで含めて記録することである。

蓋を閉じた操作

フリーズ直前のログを見ると、ノートPCの蓋を閉じた記録がある。

$ journalctl -b -1 | grep -iE "lid|PM: suspend" | tail -5
systemd-logind[1236]: Lid opened.
systemd-logind[1236]: Lid closed.
systemd-logind[1236]: Lid opened.
systemd-logind[1236]: Lid closed.
  • 00:49:47 に Lid closed。ログはその21秒後に途切れる。時系列だけ見れば一番あやしい
  • しかし同じ晩の 23:37:36 と 00:14:41 にも蓋を閉じており、そのときは何も起きていない
  • どちらのタイミングでも PM: suspend entry が一度も出ていない。つまりこの機体は蓋を閉じてもサスペンドしない設定であり、蓋の開閉自体はカーネルにとって「ただのイベント」でしかない

👉 相関はあるが因果ではない。
「直前に起きたこと」は犯人に見えやすい。疑う前に、同じ操作が過去にも何度も起きて無事だったかを確認する。それだけで容疑者リストから外せることは多い。

バッテリー

もう一つの容疑者はバッテリーである。

  • 00:44:15、ファイルインデクサが Running on LOW Battery, pausing を出している
  • バッテリーは設計容量 38.48Wh に対し、満充電時 12.27Wh まで劣化していた(設計比 31.9%)

これはフリーズの直接原因だと断定はしない。電源が落ちた形跡(強制電源断以前の電圧低下シャットダウンなど)はログ上ない。ただし、CPU も I/O もフルスロットルの状態で、電源側にも余裕がない劣化バッテリーが繋がっていたのは事実であり、これは今回のフリーズとは切り離した別のリスクとして記録しておく。


対策

ここまでの調査結果を踏まえると、対策は「メモリを守る」だけでは足りない。実際に詰まったのは I/O と CPU だったからである。優先順位をつけて並べる。

  1. 同時実行を減らす

    これが、今回のフリーズを最も直接的に防げたはずの対策である。4コア機で proc/s が87〜105(fork/exec の連発)という状態は、単純に載せすぎている。ブラウザの自動テスト・開発サーバー・エディタを何本も同時に立ち上げるような使い方自体を見直す。

  2. earlyoom を入れる

    sudo apt install earlyoom
    

    earlyoom は空きメモリと空きスワップの割合を監視し、閾値を割ったプロセスを OOM Killer より先に殺してくれるツールである。メモリの軸——今回 pgsteal/s が 0 から 3254.62 まで急悪化していった軸——に対する保険としては入れる価値がある。

    👉 ただし正直に言うと、今回のフリーズはおそらく earlyoom では防げなかった。earlyoom の既定の発動条件は「空きメモリ10%未満 かつ 空きスワップ10%未満」だが、実測の空きメモリ(kbavail)は8〜11GB(16GB中50〜68%)、空きスワップも80%(使用率19.87%)残っており、どちらの閾値にも遠く届いていない。earlyoom はメモリ枯渇の保険であって、I/O 詰まりの保険ではない。

  3. スワップを RAM 以下に減らす/zram を検討する

    スワップ32GB(RAM の2倍)は、カーネル OOM Killer が「まだ逃がせる」と判断し続ける猶予を広げ、マシンが劣化したまま生き続ける時間を延ばしていた(詳細は前章)。なお SwapUsedLimit=90% という systemd-oomd 側の閾値は、②で見たとおり Swap Monitored CGroups が空で、そもそもスワップのサイズによらず不発だった。RAM 以下のサイズに戻せば、少なくとも OOM Killer が発動するまでの猶予は今より短くなる。ただし実測のスワップ使用量は最大でも約6GB(%swpused で17〜20%)、%memused も34〜40%にとどまっており、仮に半分にしていたとしても OOM Killer の発動ラインには程遠かった。

    zram はさらに一歩踏み込んだ選択肢になる。zram は圧縮した状態でメモリ内にスワップ領域を作るため、スワップ I/O がディスクへ発生しない。今回 pswpout/s は00:40:16時点で257.05まで増えており、これはディスク I/O の一部を占めていた。zram はこのスワップ由来の I/O を取り除く——I/O の軸全体ではなく、そのうちのスワップ分への対策である。②の earlyoom がメモリ軸への保険にとどまるのに対し、zram はその一部について今回の詰まり所に直接効く数少ない対策である。

  4. PSI を監視に載せる

    これが本記事の実質的な結論である。今回、詰まった軸を最終的に特定できたのは sar -q ALL の PSI 出力だった。これを日常の監視に組み込む。

    # 今この瞬間の圧力を見る
    cat /proc/pressure/io
    
    # 履歴として残す(sysstat が入っていれば既に取れている)
    sar -q ALL -f /var/log/sysstat/sa$(date +%d)
    

    sysstat が未導入なら、導入も難しくない。

    sudo apt install sysstat
    sudo sed -i 's/^ENABLED=.*/ENABLED="true"/' /etc/default/sysstat
    sudo systemctl enable --now sysstat
    

    👉 フリーズしてから入れても遅い。 平常時に入れておいて初めて、次に固まったときの「詰まった軸」を後から復元できる。


まとめ:事後調査チートシート

今回の調査で実際に使ったコマンドを、目的別に一覧にしておく。

目的 コマンド 見るべき値
ブートの境界を掴む journalctl --list-boots 前回ブートの終了時刻に断絶があるか
強制電源断の確認 journalctl -b 0 | grep -iE "dirty bit|not properly" Dirty bit is set
パニックの有無 journalctl -b -1 | grep -E "BUG:|soft lockup|hung_task" 0件ならカーネルは生きていた
OOM の有無 journalctl -b -1 | grep -i "oom-kill" 0件でも安心しない
CPU と I/O の切り分け sar -u -f /var/log/sysstat/saNN %idle と %iowait
メモリの逼迫 sar -B -f ... pgsteal/s の増加率(%memused ではない)
スワップの動き sar -W -f ... pswpout/s が立ち上がった時刻
詰まった軸の特定 sar -q ALL -f ... %fio / %fmem / %scpu
安全網の構え oomctl Swap Monitored CGroups が空でないか
負荷の中身 sar -q / sar -w ldavg-1、proc/s

最後に3行でまとめる。

  • OOM Killer が出ていないことは、メモリが足りていたことを意味しない
  • 逼迫している軸と、実際にマシンが止まっている軸は一致するとは限らない(今回はメモリの回収負荷が急増したが、実際に止まったのは I/O だった)
  • そして詰まる軸はメモリとは限らない。PSI を見れば、どこで止まっていたか分かる

0
0
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
0
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?