はじめに
Redisクラスタの運用中に、RDBの一時ファイルが増殖してディスク容量を圧迫する問題が発生しました。
一時ファイルを削除することで暫定的に解消しましたが、原因について詳しく調査したのでまとめます。
前提
- Redis 5.0
- 仮想マシン上に構築したRedisクラスタ
- ノードあたりのデータ量は25GB程度
-
redis.confに以下を設定していて、RDBの定期スナップショットが有効save 900 1 save 300 10 save 60 10000
RDBの一時ファイルが増殖する問題が発生
RDB機能が有効な場合、メモリ上のデータのスナップショットを、RDBファイル (dump.rdb)として定期的にディスクに取得します。
今回、ディスク容量圧迫のアラートを検知したため確認してみると、あるreplicaノードでRDBの一時ファイル (temp-*.rdb)が大量に残っていました。
% ls -alh /var/run/redis
total 134G
drwxr-xr-x 3 redis redis 4.0K Aug 3 15:11 .
drwxr-xr-x 29 root root 820 Aug 2 04:44 ..
-rw-r--r-- 1 redis redis 823 Aug 2 04:28 cluster.conf
-rw-r--r-- 1 redis redis 26G Aug 2 04:33 dump.rdb
-rw-r--r-- 1 redis redis 5 Aug 2 04:44 redis.pid
srwxrwxrwx 1 redis redis 0 Aug 2 04:44 redis.sock
-rw-r--r-- 1 redis redis 7.4G Jan 19 2022 temp-12141.rdb
-rw-r--r-- 1 redis redis 7.3G May 10 04:27 temp-13611.rdb
-rw-r--r-- 1 redis redis 7.3G May 11 03:05 temp-14999.rdb
-rw-r--r-- 1 redis redis 7.3G Jun 7 07:15 temp-15699.rdb
-rw-r--r-- 1 redis redis 0 Jul 28 2020 temp-1595917757.14277.rdb
-rw-r--r-- 1 redis redis 0 Jul 28 2020 temp-1595918353.17613.rdb
-rw-r--r-- 1 redis redis 0 Jul 28 2020 temp-1595918678.19263.rdb
-rw-r--r-- 1 redis redis 7.3G Jul 5 07:21 temp-23191.rdb
-rw-r--r-- 1 redis redis 7.3G Jul 12 05:01 temp-24196.rdb
-rw-r--r-- 1 redis redis 7.3G May 17 05:26 temp-24734.rdb
-rw-r--r-- 1 redis redis 7.3G Aug 2 04:43 temp-25529.rdb
-rw-r--r-- 1 redis redis 7.3G Jul 26 06:02 temp-25627.rdb
-rw-r--r-- 1 redis redis 7.2G Jun 21 07:00 temp-28809.rdb
-rw-r--r-- 1 redis redis 7.2G May 24 05:59 temp-29536.rdb
-rw-r--r-- 1 redis redis 7.3G Jul 19 04:41 temp-31085.rdb
-rw-r--r-- 1 redis redis 7.2G May 31 04:36 temp-31250.rdb
-rw-r--r-- 1 redis redis 7.3G Jun 28 07:19 temp-4039.rdb
-rw-r--r-- 1 redis redis 7.2G Jun 14 07:01 temp-8446.rdb
Redisはdump.rdbをアトミックに更新するため、
-
temp-*.rdbという一時ファイルを生成 - それを
dump.rdbにリネームする
という処理を実行するのですが、通常であれば、スナップショットの取得完了後に一時ファイルは自動で削除されるはずです。
Redisのログを調査してみる
問題の原因を特定するため、一時ファイルの作成日時付近のRedisログを確認してみます。
25529:S 02 Aug 2022 04:42:09.855 * Trying a partial resynchronization (request bf151fb3fd92255731f4864cd03142f81d45801a:23370173).
25529:S 02 Aug 2022 04:42:09.855 * Successful partial resynchronization with master.
25529:S 02 Aug 2022 04:42:09.856 * MASTER <-> REPLICA sync: Master accepted a Partial Resynchronization.
25529:signal-handler (1659382931) Received SIGTERM scheduling shutdown...
25529:S 02 Aug 2022 04:42:11.260 # User requested shutdown...
25529:S 02 Aug 2022 04:42:11.260 * Saving the final RDB snapshot before exiting.
どうやらSIGTERMによりRedisのシャットダウンが実行されたようです。
RDB機能が有効な場合、通常はRedisのシャットダウン時にもスナップショットを取得するため、スナップショット取得の開始ログが最終行に残っています。
しかし、通常続けて表示される、以下のようなスナップショットの完了ログはありませんでした。
[6716] 02 Aug 15:48:44 * DB saved on disk
[6716] 02 Aug 15:48:44 # Redis is now ready to exit, bye bye...
以上より、スナップショットの取得完了前にRedisが強制終了している、と推測しました。
判明した原因
今回の問題の原因としては、Redisクラスタの障害試験等を実施するにあたり、Redisを事前に停止せずreplicaノードの仮想マシンのrebootを繰り返し実行していたことが原因でした。
仮想マシンのreboot実行により、RedisはSIGTERMを受け取ってシャットダウン処理を開始するが、スナップショットの取得途中に仮想マシンが終了していました。
これにより、作成途中の一時ファイルが残ってしまったようです。
問題の深堀り
今回の問題に関して、RDBファイル生成の流れを深堀りしてみようと思います。
RDBファイルが生成されるケース
RedisがRDBファイルを生成するケースは次の2通りあります。
- RDB Save
- SAVE / BGSAVEコマンドの実行時、およびsave設定による定期スナップショットの取得時とRedis終了時に生成されるRDBファイル
- 処理の流れ
-
temp-<プロセスID>.rdbという一時ファイルを生成 - 一時ファイルを
dump.rdbにリネーム
-
- 処理コード
- Full Sync
- primary-replica間のFull Sync時に生成されるRDBファイル
-
repl-diskless-syncがno (デフォルト)の場合
-
- 処理の流れ
- replicaで
temp-<unixtime>.<プロセスID>.rdbという一時ファイルをOpen - primaryでRDB Saveを実行し、その
dump.rdbをreplicaに転送して一時ファイルへ書き込む - 一時ファイルを
dump.rdbにリネーム -
dump.rdbをメモリに読み込む
- replicaで
- 処理コード
- primary-replica間のFull Sync時に生成されるRDBファイル
上記において、BGSAVE実行時、および定期スナップショット取得時における<プロセスID>は、RDB Saveのためにバッググラウンドで実行される子プロセスIDを示します。
Redis終了時のスナップショット取得
RDB機能が有効な場合、通常はRedisのシャットダウン時にもスナップショットを取得します。
SHUTDOWNコマンドの実行による通常の終了処理では、次のprepareForShutdown()関数が実行されます。
https://github.com/redis/redis/blob/704ba5f5b22ae1ecafbcfb7a3258311c27ff94ff/src/server.c#L2805-L2875
このときの処理は以下の流れです。
- バックグラウンドでRDB Save中であれば、RDB Saveを中断して一時ファイル削除
- 終了前に再度RDB Save
- Redis終了
対して、RedisがSIGINTやSIGTERMを受け取った場合は、シグナルハンドラである次のsigShutdownHandler()関数が実行されます。
https://github.com/redis/redis/blob/704ba5f5b22ae1ecafbcfb7a3258311c27ff94ff/src/server.c#L3984-L4013
このときの処理は以下の流れです。
- SIGINT受信2回目の場合は、一時ファイルを削除してRedis強制終了
- RDBをメモリにload中ならRedis終了
-
prepareForShutdown()へ
ちなみに、Redis 7ではSIGINTとSIGTERMを受け取った場合のRDB Saveの挙動について、shutdown-on-sigint / shutdown-on-sigtermに以下のオプション (一部抜粋)を設定することで指定できます。
- default: save設定がされている場合のみRDB Saveする
- save: save設定の有無にかかわらず、常にRDB Saveする
- nosave: save設定の有無にかかわらず、常にRDB Saveしない
RDBの一時ファイルが残るケース
これまでの調査で分かったこととして、RDB Save / Full Sync中に
- Redisが稼働しているサーバが強制終了する
- OOM killer等のSIGKILL受信によりRedisが強制終了する
という状況が発生すると、RDBの一時ファイルが残る可能性がありそうです。
おわりに
一時ファイルが残り続けるのを完全に防止することは難しいですが、次のような対策により多くの状況では回避ができそうです。
- 事前にRedisを停止してから仮想マシンをrebootする
- 仮想マシンの起動スクリプトで一時ファイルを削除する
- cron等でスクリプトを動かし、最新でない一時ファイルを定期的に削除する
また、永続化が不要な状況ではRDB機能を無効化するのも1つの手段です。
今回はディスク容量監視のアラートを設定していたおかげで問題に気づけたため、監視導入の重要性を改めて実感しました。