AlmaLinux 9 のサーバが時々長時間応答しなくなる原因が (たぶん) dnf makecache だった

先にまとめ

AlmaLinux 9 ではデフォルトで 1-2h 毎に dnf makecache が実行される。この処理はメモリを 1GB 以上使う可能性があり、メモリが足りている場合は数秒で終了するが、不足している場合はスワップアウトが発生し、著しくサーバのパフォーマンスを低下させる場合がある。

これを回避するには systemctl stop dnf-makecache.timer && systemctl disable dnf-makecache.timer で定期実行を停止し、必要に応じて microdnf や dnf5 の採用を検討する。

経緯

EC2 で運用している AlmaLinux 9 のサーバが数週間に 1 回程度 HTTP や SSH に応答しなくなり、再起動が必要だったり、1 時間程度かかって復旧するという現象に悩まされていた。

状況はこんな感じ↓

• zabbix によりメモリや CPU の監視をしていたが、応答しない期間はデータが取れず、その前後でもリソースの変化がほとんどない。
• ログもその期間はほとんど出力されていない。cron の実行を遅延したログくらい。
• この現象の調査のために、1 分ごとに CPU / メモリ / IO / ネットワークの使用量の多いプロセスを記録するスクリプトを作成して実行していたが、これも応答がない期間はログが取れず (cron で実行をスケジュールしていたが実行が遅延された)、前後でも多くのリソースを使っているプロセスがなかった。

と、とにかくログがないので調査に難航していたが、何度かこれを繰り返しているうちに応答がなくなる前の /var/log/messages に dnf のログがよくある事に気付いた。

# 時間・IP アドレスは適当に加工、コメントを追加
Nov 14 11:13:33 ip-x-x-x-x dnf[4066440]: AlmaLinux 9 - AppStream                         5.9 kB/s | 4.2 kB     00:00
Nov 14 11:13:34 ip-x-x-x-x dnf[4066440]: AlmaLinux 9 - BaseOS                            6.4 kB/s | 3.8 kB     00:00
Nov 14 11:13:34 ip-x-x-x-x dnf[4066440]: AlmaLinux 9 - Extras                            6.1 kB/s | 3.8 kB     00:00
Nov 14 11:13:35 ip-x-x-x-x dnf[4066440]: Extra Packages for Enterprise Linux 9 - x86_64   25 kB/s | 9.3 kB     00:00
Nov 14 11:13:37 ip-x-x-x-x dnf[4066440]: Extra Packages for Enterprise Linux 9 - x86_64   12 MB/s |  23 MB     00:01
# この時点から応答なし
# 再起動
Nov 14 12:13:25 ip-x-x-x-x kernel: The list of certified hardware and cloud instances for Red Hat Enterprise Linux 9 can be viewed at the Red Hat Ecosystem Catalog, https://catalog.redhat.com.

同様のログは平時に何度も出力されていたので、無関係だと思っていたが、調べてみることにした。

/var/log.dnf.log をみると dnf makecache --timer というコマンドで実行されているようだ。

2024-11-14T11:13:32+0900 DDEBUG Command: dnf makecache --timer

cron の設定を探しても該当するものが無かったが、systemd を使ったサービス dnf-makecache.timer で実行しているようだった。設定ファイルは下記の通りで、OS 起動後 10min 後に初回の実行、その後 1h 経ったら最大 60min のディレイを入れて実行を繰り返すようだ。

$ systemctl cat dnf-makecache.timer
# /usr/lib/systemd/system/dnf-makecache.timer
[Unit]
Description=dnf makecache --timer
ConditionKernelCommandLine=!rd.live.image
# See comment in dnf-makecache.service
ConditionPathExists=!/run/ostree-booted
Wants=network-online.target

[Timer]
OnBootSec=10min
OnUnitInactiveSec=1h
RandomizedDelaySec=60m
Unit=dnf-makecache.service

[Install]
WantedBy=timers.target

dnf makecache は dnf のパッケージのメタデータを更新するコマンド。そんなに負荷の高い処理には思えなかったが実際に実行してみることにした。

dnf clean all && dnf makecache でキャッシュをクリアして実行。実行時間は 18s 程度だったが、 vmstat 1 で監視していたところ、スワップアウトが発生していた。実行前 Available memory (free + cache) が 900MB ほどあるので 1GB 以上使っていそう。

$ vmstat 1
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 0  0  73728 690324      0 232544    0    0     0   357  146  188  0  0 100  0  0
 1  0  73728 690072      0 232564    0    0    52    44  688  453 11  2 83  0  3
 1  0  73728 660588      0 243472   48    0    97  8496 1911  778 23  4 66  0  7
 2  0  73728 641624      0 243492    0    0     0     8 1192  238 40  2 50  0  8
 0  0  73728 657500      0 251160    0    0     4     0  778  182 23  1 72  0  4
 0  0  73728 646664      0 256200    0    0     4  2380 1403  484 28  2 69  1  2
 0  0  73728 646664      0 256392    0    0    77    48  666  373 11  0 88  0  1
 1  0  73728 610652      0 279744    0    0    25 23468 5407 1010 33  6 57  2  4
 1  0  73728 571400      0 287624    0    0     0     0 1127  139 47  2 50  0  2
 1  0  73728 518468      0 287680    0    0     0     0 1124  133 46  1 50  0  2
 1  0  73728 498056      0 287680    0    0     0     0 1145  123 48  1 50  0  2
 1  0  73728 528544      0 298516    0    0     0     8 1100  125 48  2 50  0  0
 1  0  73728 512268      0 305396    0    0     0     0 1109  118 47  3 50  0  0
 2  0  73728 186256      0 305464    0    0     0     0 1171  139 36  6 50  0  9
 2  0 138240 728832      0 189260   52 64572  3540 104860 9101 1047 30 22 34  1 13
 1  0 138240 656840      0 243356    0    0 34156     0 1496  231 35  2 50  2 13
 2  0 138240 690664      0 253480   12    0  4908  5872 1534  623 30  3 49  8 10
 0  0 138240 788720      0 254408  120    0  1060     0  226  175  1  0 97  1  0
 0  0 138240 788216      0 255668    0    0  1440     0  280  293  0  0 99  0  1

おそらくほかのサービスがメモリを多く使っているときに dnf makecache が実行され、大量のスワップアウトが発生、著しくパフォーマンスが低下して応答しなくなったと推察した。

メモリがある程度足りていれば 1 分以内に完了するため、zabbix 等のメトリクスに現れにくかったようだ。

対処

"dnf makecache out of memory" で検索するといろいろ情報がヒットする。

No, 1 GB of RAM is not enough for package management of a Fedora based system
How to run DNF without going OOM on GCP e2-micro

下記は Fedora のフォーラムでの Packaging Team の方の 2022 年の投稿。対処として microdnf という dnf の軽量版を使うことを提案している。

The current design of the DNF package manager can cause it to use quite large amounts of memory (into the hundreds of megabytes) for most operations.
DNF operations use large amount of RAM and may fail in low-memory environments

microdnf はその後のアップデートで dnf5 という名前になり、Fedora 41 からはこれがデフォルトで採用されているようだ (参考1、参考2)。

残念ながら 2024/11/20 現在、AlmaLinux 9 のリポジトリには dnf5 がない。microdnf の使用は検討中。
ひとまず dnf-makecache.timer の実行を停止することにした。

systemctl stop dnf-makecache.timer
systemctl disable dnf-makecache.timer

ちなみに RHEL のガイドには下記の記述がある。

dnf-makecache.timer は、パッケージメターデータを自動的に更新する必要がない場合に限り無効にします。
2.2. 無効にしても安全なサービスを選択するためのガイド | Red Hat Product Documentation