27.4. 動的追跡

PostgreSQLは、データベースサーバの動的追跡をサポートする機能を提供します。これにより、外部ユーティリティをコードの特定のポイントで呼び出すことができ、追跡を行うことができるようになります。

多くの追跡やプローブ用のポイントは、すでにソースコード内部に存在します。これらのプローブはデータベースの開発者や管理者が使うことを意図しています。デフォルトでは、これらのプローブはPostgreSQLにコンパイルされません。ユーザは明示的にconfigureスクリプトでプローブを有効にするように設定する必要があります。

現在、OpenSolaris、Soralis 10、そして Mac OS X Leopardで利用可能なDTraceユーティリティのみがサポートされています。DTraceは将来FreeBSDやその他のオペレーティングシステムで利用できるようになることが予定されています。SystemTapプロジェクトではDtrace相当の機能をLinux向けに提供しています。他の動的追跡ユーティリティのサポートは、src/include/utils/probes.h内のPG_TRACEマクロ定義を変更することで、理論上は可能です。

27.4.1. 動的追跡のためのコンパイル

デフォルトでは、プローブは有効ではありません。そのため、PostgreSQLでプローブが利用できるようにするためにconfigureスクリプトで明示的に設定しなければなりません。DTraceサポートを含めるには、configureに--enable-dtraceを指定します。詳細は項15.4を参照してください。

27.4.2. 組み込み済みのプローブ

表27-3で示されるように、多くの標準的なプローブがソースコード内で提供されています。表27-4はプローブで使用している型を示しています。また、PostgreSQL内の可観測性を強化するためのプローブ追加が可能です。

表 27-3. 組み込み済みのDtraceプローブ

名前パラメータ説明
transaction-start(LocalTransactionId)新しいトランザクションの開始を捕捉するプローブ。arg0はトランザクションIDです。
transaction-commit(LocalTransactionId)トランザクションの正常終了を捕捉するプローブ。arg0はトランザクションIDです。
transaction-abort(LocalTransactionId)トランザクションの異常終了を捕捉するプローブ。arg0はトランザクションIDです。
query-start(const char *)問い合わせ処理の開始を捕捉するプローブ。arg0は問い合わせ文字列です。
query-done(const char *)問い合わせ処理の正常終了を捕捉するプローブ。arg0は問い合わせ文字列です。
query-parse-start(const char *)問い合わせのパース処理の開始を捕捉するプローブ。arg0は問い合わせ文字列です。
query-parse-done(const char *)問い合わせのパース処理の正常終了を捕捉するプローブ。arg0は問い合わせ文字列です。
query-rewrite-start(const char *)問い合わせの書き換え処理の開始を捕捉するプローブ。arg0は問い合わせ文字列です。
query-rewrite-done(const char *)問い合わせの書き換え処理の正常終了を捕捉するプローブ。arg0は問い合わせ文字列です。
query-plan-start()問い合わせのプランナ処理の開始を捕捉するプローブ。
query-plan-done()問い合わせのプランナ処理の正常終了を捕捉するプローブ。
query-execute-start()問い合わせの実行(エクゼキュータ)処理の開始を捕捉するプローブ。
query-execute-done()問い合わせの実行(エクゼキュータ)処理の正常終了を捕捉するプローブ。
statement-status(const char *)サーバプロセスによるpg_stat_activity.current_queryの状態の更新を捕捉するプローブ。 arg0は新しい状態の文字列です。
checkpoint-start(int)チェックポイントの開始を捕捉するプローブです。arg0はチェックポイントの種類の違い(shutdown、immediate、force)を区別するためのビットフラグを持っています。
checkpoint-done(int, int, int, int, int)チェックポイントの正常終了を捕捉するプローブ(以下に示すプローブはチェックポイント進行に従い順番に捕捉されます)。 arg0は書き込まれたバッファ数、arg1はバッファの総数、arg2、3、4はそれぞれ追加、削除、再利用されたxlogの数です。
clog-checkpoint-start(bool)CLOG部分のチェックポイントの開始を捕捉するプローブ。arg0がtrueならば通常のチェックポイントであり、falseならばシャットダウン時のチェックポイントを示します。
clog-checkpoint-done(bool)CLOG部分のチェックポイントの正常終了を捕捉するプローブ。arg0はclog-checkpoint-startと同じ意味を持ちます。
subtrans-checkpoint-start(bool)サブトランザクション部分のチェックポイントの開始を捕捉するプローブ。arg0がtrueならば通常のチェックポイントであり、falseならばシャットダウン時のチェックポイントを示します。
subtrans-checkpoint-done(bool)サブトランザクション部分のチェックポイントの正常終了を捕捉するプローブ。arg0はsubtrans-checkpoint-startと同じ意味を持ちます。
multixact-checkpoint-start(bool)マルチトランザクション部分のチェックポイントの開始を捕捉するプローブ。arg0がtrueならば通常のチェックポイントであり、falseならばシャットダウン時のチェックポイントを示します。
multixact-checkpoint-done(bool)マルチトランザクション部分のチェックポイントの正常終了を捕捉するプローブ。arg0はmultixact-checkpoint-startと同じ意味を持ちます。
buffer-checkpoint-start(int)チェックポイントのバッファ書き込み部分の開始を捕捉するプローブ。arg0はチェックポイントの種類の違い(shutdown、immediate、force)を区別するためのビットフラグを持っています。
buffer-sync-start(int, int)チェックポイント中のダーティバッファの書き出し開始を捕捉するプローブ(どのバッファが書き出す必要があるのかを判定した後です)。arg0はバッファの総数で、arg1は現在ダーティであり、書き出す必要のあるバッファ数です。
buffer-sync-written(int)チェックポイント中のそれぞれのバッファを書き出し後を捕捉するプローブ。arg0はバッファのIDを示します。
buffer-sync-done(int, int, int)全てのダーティバッファの書き出し後を捕捉するプローブ。arg0はバッファの総数です。arg1はチェックポイント処理により実際に書き出されたバッファ数です。arg2は書き出されるであろうと見積もられたバッファ数(buffer-sync-startのarg1相当)です。この違いはチェックポイント中に他のプロセスにより書き出されたバッファ分です。
buffer-checkpoint-sync-start()カーネルへのダーティバッファの書き出し処理発行の後、そして同期書き出し要求を開始する前を捕捉するプローブ。
buffer-checkpoint-done()バッファからディスクへの同期書き出し処理の終了を捕捉するプローブ。
twophase-checkpoint-start()二相コミット部分のチェックポイントの開始を捕捉するプローブ。
twophase-checkpoint-done()二相コミット部分のチェックポイントの正常終了を捕捉するプローブ。
buffer-read-start(ForkNumber, BlockNumber, Oid, Oid, Oid, int, bool) バッファ読み込みの開始を捕捉するプローブ。arg0はとarg1は読み込みページのフォーク番号とブロック番号です(ただし、リレーションの拡張要求があった場合、arg1は-1になるでしょう)。 arg2、arg3、arg4は対象のリレーションを識別するテーブル空間、データベース、そしてリレーションのOIDです。 arg5は一時テーブルをローカルバッファに作成していればそのバックエンドのIDであり、無効なバックエンドID(-1)であれは共有バッファを指します。 arg6はtrueならばリレーションの拡張要求、falseは通常の読み込みを示します。
buffer-read-done(ForkNumber, BlockNumber, Oid, Oid, Oid, int, bool, bool)バッファ読み込みの終了を捕捉するプローブ。arg0とarg1は読み込みページのフォーク番号とブロック番号です(もしリレーションの拡張要求があった場合、arg1は新たに追加されたブロックの番号を含みます)。 arg2、arg3、arg4は対象のテーブルを識別するテーブル空間、データベース、そしてテーブルのOIDです。arg5は一時テーブルをローカルバッファに作成していればそのバックエンドのIDであり、無効なバックエンドID(-1)であれは共有バッファを指します。 arg6はtrueならばリレーションの拡張要求、falseは通常の読み込みを示します。arg7はtrueならばバッファがプール内にある、falseはプール内に無かったことを示します。
buffer-flush-start(ForkNumber, BlockNumber, Oid, Oid, Oid)共有バッファへの書き込み要求開始を捕捉するプローブ。arg0とarg1はそのページのフォーク番号とブロック番号です。arg2、arg3、arg4は対象のリレーションを識別するテーブル空間、データベース、そしてテーブルのOIDです。
buffer-flush-done(ForkNumber, BlockNumber, Oid, Oid, Oid)書き込み要求の終了を捕捉するプローブ。(これはカーネルへデータを渡したタイミングのみを反映していることに注意してください; 大抵、この時点ではまだ実際にディスクへ書き込まれていません。)引数はbuffer-flush-startと同じです。
buffer-write-dirty-start(ForkNumber, BlockNumber, Oid, Oid, Oid)サーバプロセスによるダーティバッファの書き出し開始を捕捉するプローブ。(もしこれが頻発するようでしたら、shared_buffersが少な過ぎるか、バックグラウンドライタ制御のパラメータの調節が必要なことを意味します。)arg0とarg1はそのページのフォーク番号とブロック番号です。arg2、arg3、arg4は対象のリレーションを識別するテーブル空間、データベース、そしてリレーションのOIDです。
buffer-write-dirty-done(ForkNumber, BlockNumber, Oid, Oid, Oid)ダーティバッファの書き出しの終了を捕捉するプローブです。引数はbuffer-write-dirty-startと同じです。
wal-buffer-write-dirty-start()WALバッファ領域の不足によるサーバプロセスのダーティなWALバッファを書き出しを捕捉するプローブ。(もしこれが頻発するようでしたら、wal_buffersが小さすぎることを意味します。)
wal-buffer-write-dirty-done()ダーティなWALバッファの書き出し終了を捕捉するプローブ。
xlog-insert(unsigned char, unsigned char)WALレコードの挿入を捕捉するプローブ。arg0はレコードのリソースマネージャ(rmid)です。arg1は情報フラグです。
xlog-switch()WALセグメントのスイッチ要求を捕捉するプローブです。
smgr-md-read-start(ForkNumber, BlockNumber, Oid, Oid, Oid, int)リレーションからのブロック読み込みの開始を捕捉するプローブ。arg0とarg1はそのページのフォーク番号とブロック番号です。arg2、arg3、arg4は対象のリレーションを識別するテーブル空間、データベース、そしてリレーションのOIDです。arg5は一時テーブルをローカルバッファに作成していればそのバックエンドのIDであり、無効なバックエンドID(-1)であれは共有バッファを指します。
smgr-md-read-done(ForkNumber, BlockNumber, Oid, Oid, Oid, int, int, int)ブロックの読み込み終了を捕捉するプローブ。arg0とarg1はそのページのフォーク番号とブロック番号です。arg2、arg3、arg4は対象のリレーションを識別するテーブル空間、データベース、そしてリレーションのOIDです。arg5は一時テーブルをローカルバッファに作成していればそのバックエンドのIDであり、無効なバックエンドID(-1)であれは共有バッファを指します。arg6は実際に読み込んだバイト数、arg7はリクエストされた読み込みバイト数です(もし、これらに差異があった場合、何らかの問題があることを示します)。
smgr-md-write-start(ForkNumber, BlockNumber, Oid, Oid, Oid, int)リレーションへのブロック書き出しの開始を捕捉するプローブ。arg0とarg1はそのページのフォーク番号とブロック番号です。arg2、arg3、arg4は対象のリレーションを識別するテーブル空間、データベース、そしてリレーションのOIDです。arg5は一時テーブルをローカルバッファに作成していればそのバックエンドのIDであり、無効なバックエンドID(-1)であれは共有バッファを指します。
smgr-md-write-done(ForkNumber, BlockNumber, Oid, Oid, Oid, int, int, int)ブロックの書き出し終了を捕捉するプローブ。arg0とarg1はそのページのフォーク番号とブロック番号です。arg2、arg3、arg4は対象のリレーションを識別するテーブル空間、データベース、そしてリレーションのOIDです。arg5は一時テーブルをローカルバッファに作成していればそのバックエンドのIDであり、無効なバックエンドID(-1)であれは共有バッファを指します。arg6は実際に書き出したバイト数、arg7はリクエストされた書き出しバイト数です(もし、これらに差異があった場合、何らかの問題があることを示します)。
sort-start(int, bool, int, int, bool)ソート処理の開始を捕捉するプローブ。arg0は対象データがヒープ、インデックス、またはdatumのどれかを示します。arg1はtrueならば一意性を必要としていることを示します。arg2はカラムのキー数です。arg3は許容されている作業メモリ(work_mem)のキロバイト数です。arg4はtrueならばソート結果に対するランダムアクセスが要求されていることを示します。
sort-done(bool, long)ソート処理の終了を捕捉するプローブ。arg0はtrueならば外部ソート、falseは内部ソートを示します。arg1は外部ソートで使用されたディスクブロック数、もしくは内部ソートで使用されたメモリーのキロバイト数を示します。
lwlock-acquire(LWLockId, LWLockMode)LWLock(軽量ロック)の取得を捕捉するプローブ。arg0は軽量ロックのIDを示します。arg1は要求されたロックモード(排他、もしくは共有)を示します。
lwlock-release(LWLockId)軽量ロックの開放を捕捉するプローブ(ただし、開放待ちのプロセスはまだこのロックを取得できないことに注意して下さい)。arg0は軽量ロックのIDを示します。
lwlock-wait-start(LWLockId, LWLockMode)軽量ロックを即座に取得できなかったため、サーバプロセスがロックを利用できるまでロック待機状態になった際の開始を捕捉するプローブ。arg0は軽量ロックのIDを示します。arg1は要求されたロックモード(排他、もしくは共有)を示します。
lwlock-wait-done(LWLockId, LWLockMode)サーバプロセスの軽量ロック待機の開放を捕捉するプローブ(実際にはまだロックは取得していません)。arg0は軽量ロックのIDを示します。arg1は要求されたロックモード(排他、もしくは共有)を示します。
lwlock-condacquire(LWLockId, LWLockMode)呼び出し元が待機しないことを指定した際の、軽量ロックの獲得成功を捕捉するプローブ。arg0は軽量ロックのIDを示します。arg1は要求されたロックモード(排他、もしくは共有)を示します。
lwlock-condacquire-fail(LWLockId, LWLockMode)呼び出し元が待機しないことを指定した際の、軽量ロックの獲得失敗を捕捉するプローブ。arg0は軽量ロックのIDを示します。arg1は要求されたロックモード(排他、もしくは共有)を示します。
lock-wait-start(unsigned int, unsigned int, unsigned int, unsigned int, unsigned int, LOCKMODE)通常のロック(lmgr lock)を即座に取得できなかったため、サーバプロセスがロックを利用できるまでロック待ち状態になった際の開始を捕捉するプローブ。arg0からarg3はロックされたオブジェクトの識別用タグ領域です。arg4はロックされたオブジェクトのタイプを示します。arg5は要求されたロックの種類を示します。
lock-wait-done(unsigned int, unsigned int, unsigned int, unsigned int, unsigned int, LOCKMODE)通常のロック(lmgr lock)要求の待機終了を捕捉するプローブ(つまりロックを取得した)。 引数はlock-wait-startと同じです。
deadlock-found()デッドロック検知器によるデッドロックの発見を捕捉するプローブ。

表 27-4. プローブパラメータで使われる型の定義

定義
LocalTransactionIdunsigned int
LWLockIdint
LWLockModeint
LOCKMODEint
BlockNumberunsigned int
Oidunsigned int
ForkNumberint
boolchar

27.4.3. プローブの利用

以下の例では、システムにおけるトランザクション数を解析するDTraceスクリプトを示します。性能試験前後でpg_stat_databaseのスナップショットを取ることで代替可能です。

#!/usr/sbin/dtrace -qs

postgresql$1:::transaction-start
{
      @start["Start"] = count();
      self->ts  = timestamp;
}

postgresql$1:::transaction-abort
{
      @abort["Abort"] = count();
}

postgresql$1:::transaction-commit
/self->ts/
{
      @commit["Commit"] = count();
      @time["Total time (ns)"] = sum(timestamp - self->ts);
      self->ts=0;
}

実行すると、例のDスクリプトは以下のような出力をします。

# ./txn_count.d `pgrep -n postgres` or ./txn_count.d <PID>
^C

Start                                          71
Commit                                         70
Total time (ns)                        2312105013

注意: 基本となる追跡ポイントの互換性はありますが、SystemTapはDTraceと異なる追跡スクリプトの表記を用います。 表記に関して特に注意すべき点として、SystemTapでは参照する追跡ポイント名のハイフンの代わりに二重のアンダースコアを用いる必要があります。 これは将来的なSystemTapのリリースで修正されることを期待しています。

DTraceスクリプトの作成には注意が必要であり、デバッグが必要であることは忘れないでください。さもないと、収集される追跡情報の意味がなくなるかもしれません。ほとんどの場合、見つかる問題はシステムではなく使用方法の間違いです。動的追跡を使用して見つかった情報に関して議論を行う際には、スクリプトの検査や議論もできるようにスクリプトも含めるようにしてください。

さらに多くのサンプルスクリプトがPgFoundryのdtrace projectにあります。

27.4.4. 新規プローブの定義

開発者が望めばコード内に新しくプローブを定義することができます。しかし、これには再コンパイルが必要です。下記は、新規プローブの定義の手順です。

  1. プローブの名前とプローブの処理を通じて取得可能とするデータを決めます

  2. src/backend/utils/probes.dにプローブの定義を追加します

  3. もし、プローブポイントを含むモジュールがpg_trace.hをインクルードしてなければそれをインクルードし、ソースコード中のプローブを行いたい場所にTRACE_POSTGRESQLマクロを挿入します

  4. 再コンパイルを行い、新規プローブが利用できるか確認します

例: これはトランザクションIDを用いて新規トランザクションを追跡するプローブ追加の仕方の例です。

  1. プローブ名をtransaction-startとし、パラメータとしてLocalTransactionId型を必要とすることを決めます

  2. src/backend/utils/probes.dにプローブの定義を追加します:

          probe transaction__start(LocalTransactionId);

    プローブ名に二重のアンダースコアを使用する場合は注意して下さい。DTraceスクリプトでプローブを用いる場合、二重のアンダースコアをハイフンに置き換える必要があります。そのため、transaction-startがユーザ向けの文書に記載される名前となります。

  3. コンパイル時に、transaction__startTRACE_POSTGRESQL_TRANSACTION_STARTと呼ばれるマクロに変換されます(ここではアンダースコアはひとつになります)。このマクロは、pg_trace.hをインクルードすることにより使用可能となります。このマクロをソースコード中の適切な箇所へ追加していきます。この場合、以下の様になります。

        TRACE_POSTGRESQL_TRANSACTION_START(vxid.localTransactionId);

  4. 再コンパイル後に新しいバイナリでサーバを起動し、下記の様なDTraceコマンドの実行により新たに追加したプローブが利用可能なチェックします。下記の様な出力が確認できるはずです:

    # dtrace -ln transaction-start
       ID    PROVIDER          MODULE           FUNCTION NAME
    18705 postgresql49878     postgres     StartTransactionCommand transaction-start
    18755 postgresql49877     postgres     StartTransactionCommand transaction-start
    18805 postgresql49876     postgres     StartTransactionCommand transaction-start
    18855 postgresql49875     postgres     StartTransactionCommand transaction-start
    18986 postgresql49873     postgres     StartTransactionCommand transaction-start

Cのソースコードに追跡用のマクロを追加する際、いくつかの注意点があります: