xlogdumpによるトランザクションログの解析
アップタイム・テクノロジーズ合同会社
永安 悟史
この記事は、PostgreSQL Advent Calendar #13の12月13日の記事です。
今回は、「PostgreSQL内部解析の強化期間」ということですので、普段はあまり覗くことのないトランザクションログの中を覗いてみる方法を解説します。
もっとも、普段あまり気にすることはなくとも、PostgreSQLのトランザクションログはアーカイブログとして保存してリカバリに使われたり、または(ファイル単位ではなくレコード単位ですが)レプリケーションの際の通信にも使われるものですので、知っておいて損はないでしょう。
普段、ほとんど気にせず使っている機能の内部がどのようなデータ形式になっているのか、その理解の一助になれば幸いです。
はじめに
PostgreSQLは、データを障害から保護するために、データへの更新情報を時系列にトランザクションログ(WAL:Write-Ahead Log)に記録しています。
データベースへの更新はすべてトランザクションログに書き込まれますので、そのトランザクションログの内容を解析することができれば、PostgreSQLがどのように更新処理を行っているのか、その挙動を詳細に把握することが可能になります。
PostgreSQLのトランザクションログは、実際には「セグメントファイル」と呼ばれる16MB単位のファイルに分割されてデータベースクラスタ内のpg_xlogディレクトリ以下に保存されています。
xlogdumpの概要
xlogdumpは、PostgreSQLのトランザクションログ(WAL)ファイルに含まれているWALレコードの内容を読み取り、人間に分かる形で表示するユーティリティです。
snaga/xlogdump - GitHub (プロジェクトページ)
http://github.com/snaga/xlogdump
xlogdumpはもともとTom Lane氏によって開発され、Diogo Biazus氏がメンテナンスしていたプロジェクトでしたが、ここ4~5年メンテナンスされておらず(最近のPostgreSQLバージョンでは)ビルドもできない状態が続いていたため、Diogo Biazus氏と相談し、筆者がメンテナンスを引き継いたものです。なお、xlogdumpは以下のバージョンのPostgreSQLをサポートしています。
- PostgreSQL 9.1
 - PostgreSQL 9.0
 - PostgreSQL 8.4
 - PostgreSQL 8.3
 - PostgreSQL 8.2
 
xlogdumpでは、本家の開発チームによってメンテナンスされているすべてのPostgreSQLのメジャーバージョンをカバーする、というポリシーで開発・動作確認等を行うようにしています。(本家ではバージョン8.2のサポートが終了したので、xlogdumpでも近いうちに8.2のサポートが落とされる予定です)
導入手順
xlogdumpの導入は非常に簡単です。
- PostgreSQLのソースコードを準備する。
 - GitHubからxlogdumpのtar ballをダウンロードし、ソースを展開する。
 - makeコマンドでxlogdumpをビルドする。
 
という流れになります。それでは導入を始めます。
今回はPostgreSQL 9.1を用います。PostgreSQL 9.1のソースコードが展開され、configure が実行されているものとします。
まず、GitHubからxlogdumpのソースコードをダウンロードします。執筆時点ではバージョン0.5.1が最新版ですので、「xlogdump-0.5.1.tar.gz」をダウンロードします。
http://github.com/snaga/xlogdump
ダウンロードしたらPostgreSQLのcontribディレクトリに展開します。 xlogdump-0.5.1ディレクトリに移動してmakeコマンドを実行すればxlogdumpコマンドが生成されます(make installを実行すると、PostgreSQLのbinディレクトリにインストールされます)。
$ cd /path/to/postgresql-9.1.1/contrib $ tar zxf /path/to/xlogdump-0.5.1.tar.gz $ cd xlogdump-0.5.1 $ make $ sudo make install
基本的な使い方
xlogdumpは、以下のコマンドラインの書式で実行します。
xlogdump [OPTION]... [segment file(s)]
0個以上のオプションおよび1個以上のWALのセグメントファイル名を引数に取ります。 xlogdumpを実行すると、以下のような出力が表示されます。

指定できるオプション
xlogdumpで指定できるオプションは以下の通りです。
  -r, --rmid=RMID           指定したリソースマネージャID(RMID)に該当する
                            WALレコードのみを出力する。
                            RMID:Resource Manager
                               0:XLOG
                               1:Transaction
                               2:Storage
                               3:CLOG
                               4:Database
                               5:Tablespace
                               6:MultiXact
                               7:RelMap
                               8:Standby
                               9:Heap2
                              10:Heap
                              11:Btree
                              12:Hash
                              13:Gin
                              14:Gist
                              15:Sequence
  -x, --xid=XID             指定したトランザクションID(XID)に該当する
                            WALレコードのみを出力する。
  -t, --transactions        Outputs only transaction info: the xid,
                            total length and status of each transaction.
  -s, --statements          WALレコードから疑似的なSQL文の生成を試みます。
  -S, --stats               WALセグメント内の統計情報を表示します。
  -n, --oid2name            システムカタログまたはキャッシュファイルを参照し、
                            出力にOIDではなくオブジェクト名を表示します。
  -g, --gen_oid2name        システムカタログを参照し、OID2NAMEキャッシュファイル
                            (oid2name.out)を生成します。
  -T, --hide-timestamps     タイムスタンプ情報を表示しません(テスト用途)。
  -?, --help                ヘルプを表示します。
oid2nameの追加オプション:
  -h, --host=HOST           データベースホスト名またはソケットディレクトリ
  -p, --port=PORT           データベースサーバのポート番号
  -U, --user=NAME           接続するデータベース名
  -f, --file=FILE           読み込むOID2NAMEキャッシュファイル名
WALセグメントファイルの基本構造
WALセグメントファイルは、以下のような構造になっています。
出力される情報の読み方
では、出力されたレコードを読んでみましょう。以下の出力を例に取ります。(表示の関係上、一列で出力される結果を2行に分けています)
[cur:0/A001374, xid:99755, rmid:10(Heap), len:131/159, prev:0/9FFF4C8] hot_update: s/d/r:1663/32768/32806 block 1530 off 77 to block 1530 off 76
最初の「cur:0/A001374」は現在のWALレコードの位置です。xlogid/xrecoffの形で表示されています。
続く「xid:99755」は、WALレコードを生成したトランザクションのトランザクションID(XID)です。
その次の「rmid:10(Heap)」は、PostgreSQL内部のどのようなモジュールによってWALレコードが生成されたのかが表示されます。PostgreSQLは、その内部において「リソースマネージャ」という単位でモジュール化されており、それぞれにリソースマネージャID(RMID)が付与されています。「10(Heap)」というのは、ヒープ(テーブルファイルやインデックスファイルなど)を操作するモジュールによって生成された、ということです。
「len:131/159」はWALレコードの長さを示しています。前者の「131」というのはWALレコードのみ(WALレコードヘッダおよびバックアップブロックを含まない)の長さであり、後者の「159」というのはWALレコードヘッダおよびバックアップブロックも含む長さです。
「prev:0/9FFF4C8」というのは、このひとつ前のWALレコードの位置です。
ここまでが、すべてのWALレコードに共通して出力される情報です。 これ以降は、「(テーブルやインデックスファイルを操作する)Heapリソースマネージャ」における特有の出力となります。
「hot_update」というのはHOT update処理のログであることを意味しており、「s/d/r:1663/32768/32806」というのは、このHOT update処理の対象テーブルのスキーマOID(1663)、データベースOID(32768)、リレーション(テーブル)OID(32806)を示しています。
最後の「block 1530 off 77 to block 1530 off 76」というのは、ブロック番号1530のオフセット77番目からオフセット76番目にレコードを移動した、ということを示しています。このWALレコードを見ると、Update処理において対象レコードが同じブロック内で移動したことが分かります。
統計機能
見てきたようにxlogdumpでは個々のWALレコードの内容を表示することができますが、同時に統計情報を取得することもできます。 「-S, --stats」オプションを指定すると、そのWALセグメントファイルの中のWALレコード数をカウントし、リソースマネージャやその操作内容ごとに、WALレコード数やレコードサイズなどをカウントして表示します。 また、バックアップブロックのサイズも表示されますので、バックアップブロックがWALセグメント内でどの程度の容量を占めているのか、などを見ることができます。

まとめ
というわけで、以上、簡単ではありましたが、xlogdumpを使ったWALレコードの読み方、ということでご紹介しました。
トランザクションログはRDBMSのキモのひとつですし、これを読めるようになれば、PostgreSQLの動作をより明確に把握することができるようになります。 また、今後はWALレコードベースのレプリケーションが主流になると思われますので、WALレコードの中身を読みたくなるシチュエーションがさらに増えてくると思います。
昔の私の上司はよく「ダンプを眺めていればすべてが分かる」と言っていました。その意味が、今は多少は分かるような気がしています。(もっとも、その上司が眺めていたのはバイナリダンプでしたが・・・)
ぜひ、xlogdumpを使ってPostgreSQLの内部の動きを(ちょっとだけでも)覗いてみてもらえればと思います。
明日12月14日の担当は Kenichiro Tanaka 氏です。