私自身PostgreSQL本体の開発やバグ修正を何度か行っているのですが、最近リカバリ機能周りで面白いバグを修正したので、バグの発見から原因の特定、修正まで実際に行ったことを紹介しようと思います。これからPostgreSQLに貢献していきたい、開発を始めたいという方に参考になると嬉しいです。

本バグはすでに修正されているため、再現したい方は9.5.19以前、9.6.15以前、10.10以前、11.5以前のどれかを使うか、開発用ブランチを使う場合は、コミットdf86e52cace2c413よりも古いコードを利用してください

本記事ではPostgreSQLの開発用ブランチ(materブランチ)を使用しています。PostgreSQLのソースコードのダウンロードやビルドについてはこちらの記事をご参照ください。

バグの発見

Single Page Recovery1という技術をPostgreSQLに組み込むために開発していた所、PostgreSQLのタイムラインIDについて理解を深めるために、色々な動作確認や実験をしていました。

実際に行った動作確認は以下のステップです。ざっくりいうと、PITRしたデータベースから更にバックアップを取得してPITRをしています。

# データベースの作成
ninitdb -D base -E UTF8 --no-locale

# 設定ファイルの編集
cat << EOF >> base/postgresql.conf
archive_mode = on
archive_command = 'cp %p /path/to/archive/%f'
EOF

# 起動
pg_ctl start -D base
psql -c "create table a (i int primary key)"
psql -c "insert into a select generate_series(1,100)"
psql -c "checkpoint"

# 物理バックアップを取得
pg_basebackup -D bkp1 -P

# リカバリ設定
echo "restore_command = 'cp /path/to/archive/%f %p'" >> bkp1/postgresql.conf
touch bkp1/recovery.signal

# リカバリ開始(1回目)
pg_ctl stop -D base
pg_ctl start -D bkp1

# 物理バックアップを取得
pg_basebackup -D bkp2 -P

# リカバリ設定
echo "restore_command = 'cp /path/to/archive/%f %p'" >> bkp2/postgresql.conf
touch bkp2/recovery.signal

# リカバリ開始(2回目)
pg_ctl stop -D bkp1
pg_ctl start -D bkp2

(バグの再現手順はこのようにスクリプト化しておくと、修正後にバグが治っているかの確認もできるので楽です。)

上記のスクリプト実行後、2回目のリカバリ後のWAL(bkp2/pg_wal)を見てみると以下のようなファイルがあります。

00000002.history          000000030000000000000006  archive_status
000000030000000000000005  00000003.history          RECOVERYHISTORY

ここで注目するのはRECOVERYHISTORYファイルです。このファイルはドキュメントを見てもなにも説明は載っておらず、中身を見てみると00000002.historyと全く同じなので必要なさそうです。なのになぜかこのファイルが残っている、これが今回解決したい問題です。

原因解析 - RECOVERYHISTORYファイルとはなにか?-

なぜかpg_walディレクトリに存在しているRECOVERYHISTORYファイルはどのようなファイルなのでしょうか?まずは、ソースコードでRECOVERYHISTORYファイルを操作している箇所を見てみます。

$ git grep RECOVERYHISTORY
src/backend/access/transam/timeline.c:          if (RestoreArchivedFile(path, histfname, "RECOVERYHISTORY", 0, false))
src/backend/access/transam/timeline.c:                  RestoreArchivedFile(path, histfname, "RECOVERYHISTORY", 0, false);
src/backend/access/transam/timeline.c:          RestoreArchivedFile(path, histfname, "RECOVERYHISTORY", 0, false);
src/backend/access/transam/timeline.c:          RestoreArchivedFile(path, histfname, "RECOVERYHISTORY", 0, false);
src/backend/access/transam/xlog.c:      snprintf(recoveryPath, MAXPGPATH, XLOGDIR "/RECOVERYHISTORY");

RestoreArchivedFile関数が関係していることがわかります。

この関数はsrc/backend/access/transam/timeline.cに定義されているので見てみます。

/
 * Attempt to retrieve the specified file from off-line archival storage.
 * If successful, fill "path" with its complete path (note that this will be
 * a temp file name that doesn't follow the normal naming convention), and
 * return true.
 *
 * If not successful, fill "path" with the name of the normal on-line file
 * (which may or may not actually exist, but we'll try to use it), and return
 * false.
 *
 * For fixed-size files, the caller may pass the expected size as an
 * additional crosscheck on successful recovery.  If the file size is not
 * known, set expectedSize = 0.
 *
 * When 'cleanupEnabled' is false, refrain from deleting any old WAL segments
 * in the archive. This is used when fetching the initial checkpoint record,
 * when we are not yet sure how far back we need the WAL.
 */
bool
RestoreArchivedFile(char *path, const char *xlogfname,
                    const char *recovername, off_t expectedSize,
                    bool cleanupEnabled)
{

300行程ある関数ですが随所にコメントが残されているため、比較的簡単に内容は理解できると思います。関数を読んでみるとこのコマンドは、以下のような動作をすることがわかります。

  • restore_commandパラメータに設定されたコマンドを実行し、アーカイブからファイル(WALなど)をリストアする
  • リストアが成功した場合、引数pathにはpg_walrecovername変数の値を組み合わせた文字列が設定(コード上ではxlogpath変数)されtrueが返される
  • リストアが失敗した場合は、引数pathにはxlogfnameが設定されfalseが返される

RestoreArchivedFile(path, histfname, "RECOVERYHISTORY", 0, false);のようにこの関数を使っていることから、restore_commandによってhistoryファイルがリストアされ、リストアされたファイルがRECOVERYHISTORYという名前になっている、ことがわかります

RECOVERYHITORYファイルのその後は?

RECOVERYHISTORYファイルはその後どうなるのでしょうか?答えはRestoreArchivedFile関数が使われている周辺を見るとわかります。

src/backend/access/transam/timeline.cに定義されているrestoreTimeLineHistoryFiles関数は以下のようになっています。

void
restoreTimeLineHistoryFiles(TimeLineID begin, TimeLineID end)
{
    char        path[MAXPGPATH];
    char        histfname[MAXFNAMELEN];
    TimeLineID  tli;

    for (tli = begin; tli < end; tli++)
    {
        if (tli == 1)
            continue;

        TLHistoryFileName(histfname, tli);
        if (RestoreArchivedFile(path, histfname, "RECOVERYHISTORY", 0, false))
            KeepFileRestoredFromArchive(path, histfname);
    }
}

RestoreArchivedFile関数を実行していて、さらにその後にKeepFileRestoredFromArchive関数を実行しています。KeepFileRestoredFromArchive関数のコメントを読むとわかりますが、この関数はpathに指定されたファイル名をhistfnameに変換します。つまり、ここでRECOVERYHISTORYは一時的なファイル名であり、後のコードで適切な名前に変更されることがわかります。

さらに、RECOVERYHISTORYをキーワードにもう少しコードを見てみると以下のように、アーカイブリカバリ終了時にこれらのファイルを削除しているコードも見つかります。

static void
exitArchiveRecovery(TimeLineID endTLI, XLogRecPtr endOfLog)
{
	:
	:

    /*
     * Since there might be a partial WAL segment named RECOVERYXLOG, get rid
     * of it.
     */
    snprintf(recoveryPath, MAXPGPATH, XLOGDIR "/RECOVERYXLOG");
    unlink(recoveryPath);       /* ignore any error */

    /* Get rid of any remaining recovered timeline-history file, too */
    snprintf(recoveryPath, MAXPGPATH, XLOGDIR "/RECOVERYHISTORY");
    unlink(recoveryPath);       /* ignore any error */

やはりRECOVERYHISTORY(やRECOVERYXLOG)は不必要なファイルなようです。

まとめ

今回はバグの発見、問題の理解まで書いてみました。もしPostgreSQLのバグを見つけた場合は、自分で修正しなくても、この時点で再現手順を添えてPostgreSQLコミュニティに報告しても良いと思います。コミュニティ上での議論を見たり、自分なりの調査を行うことでPostgreSQLの動作にソースコードレベルで詳しくなることができます。

次回は原因究明、解決を紹介しようと思います。興味がある方はこれらの情報を元に、ぜひ自分で何が原因になっているのかを探してみてください!

本バグの影響は?

本バグの修正は次回にリリースされるバージョンに取り込まれる予定ですので、PostgreSQLコミュニティによる公式な見解はまだですが、個人的には本バグによる影響は大きくないと考えています。RECOVERYHISTORYファイルは不必要なファイルではありますが、存在していてもPostgreSQLの動作に悪影響を及ぼすものではありません。ただし、お使いのバックアップ管理ツール等ではpg_walディレクトリ内になにか不要なファイルがあることで問題を引き起こす可能性もあるかもしれないので、念の為確認することを推奨します。

  1. おもしろい技術なのでまた今度解説します。