DataBase  /  PostgreSQL  /  レポート取得ガイド

auto_explain / スロークエリログによる取得とセクション定義

auto_explain 拡張モジュールと log_min_duration_statement を使って、 しきい値を超えた遅いクエリとその実行計画を PostgreSQL ログに自動記録する方法と、 ログ出力の各フィールドの定義を解説します。 Oracle AWR の SQL Statistics(重い SQL の自動検出)に相当します。

1. スロークエリログの設定(log_min_duration_statement)

postgresql.conf — スロークエリログ設定
# しきい値(ms)を超えたクエリをログに記録
# -1 = 無効, 0 = 全クエリ記録(負荷大)
log_min_duration_statement = 1000   # 1秒以上のクエリを記録

# ログ出力先(stderr / csvlog / jsonlog)
log_destination = 'stderr'
logging_collector = on
log_directory = 'pg_log'
log_filename = 'postgresql-%Y-%m-%d.log'
log_rotation_age = 1d
log_rotation_size = 100MB

# 各行のプレフィックス形式
log_line_prefix = '%t [%p]: [%l-1] user=%u,db=%d,app=%a,client=%h '

# 実行計画をログに記録(後述の auto_explain で設定する方が推奨)
# log_min_duration_statement だけでは実行計画は記録されない

# セッション単位での一時的な変更(pg_reload_conf() 不要)
# SET log_min_duration_statement = 500;  -- 500ms 以上
💡 リロードで反映(再起動不要)
log_min_duration_statementpg_reload_conf() または pg_ctl reload で即時反映されます。再起動は不要です。 セッション単位で SET log_min_duration_statement = 500; としてテストすることもできます。

2. スロークエリログのフィールド定義

Log — スロークエリログ エントリ例
2026-05-29 14:32:01.123 JST [12345]: [3-1] user=appuser,db=mydb,app=myapp,client=192.168.1.10
  LOG:  duration: 2345.678 ms  statement: SELECT u.user_id, u.name, COUNT(o.order_id) AS order_count
        FROM users u
        LEFT JOIN orders o ON u.user_id = o.user_id
        WHERE u.created_at >= '2025-01-01'
        GROUP BY u.user_id
        ORDER BY order_count DESC
        LIMIT 100;
フィールド説明Oracle AWR 対応
タイムスタンプ クエリが完了した日時。log_line_prefix%t または %m(ミリ秒付き)で出力。
PID [%p] バックエンドプロセスの PID。pg_stat_activity の pid と対応。 SID
user=%u 接続ユーザー名。 Username
db=%d 接続データベース名。
app=%a アプリケーション名(application_name)。 Program
client=%h クライアントのホスト名または IP アドレス。 Machine
duration: N ms クエリの実行時間(ms)。log_min_duration_statement のしきい値を超えた場合に記録。 Elapsed Time
statement 実行されたクエリテキスト(パラメータ値含む)。pg_stat_statements の正規化テキストとは異なる。 SQL_TEXT
bind / parameters プリペアドステートメントのパラメータ値。log_parameter_max_length で長さを制限可能。

3. auto_explain の設定

auto_explainlog_min_duration_statement のスロークエリログに 実行計画を自動で付加する拡張モジュールです。

postgresql.conf — auto_explain 設定
# shared_preload_libraries に追加(再起動が必要)
shared_preload_libraries = 'auto_explain'

# しきい値(ms)を超えたクエリの実行計画をログに記録
auto_explain.log_min_duration = 1000   # 1秒以上

# ANALYZE 相当の実測値を記録(true 推奨)
auto_explain.log_analyze = on

# バッファ情報を記録(log_analyze = on と組み合わせ)
auto_explain.log_buffers = on

# 実行時間を記録
auto_explain.log_timing = on

# VERBOSE 相当の詳細出力
auto_explain.log_verbose = off   # ログが大量になるため通常は off

# EXPLAIN の出力形式
auto_explain.log_format = text   # text / json / xml / yaml

# ネストされたクエリ(関数内クエリなど)も記録
auto_explain.log_nested_statements = off

# サンプリング率(0.0 〜 1.0):全件記録のオーバーヘッドを下げる(PostgreSQL 12+)
auto_explain.sample_rate = 1.0   # 1.0 = 100%(全件)
SQL — セッション単位で auto_explain を一時的に有効化
-- superuser のみ実行可能
LOAD 'auto_explain';
SET auto_explain.log_min_duration = 0;   -- 全クエリ(テスト用)
SET auto_explain.log_analyze = on;
SET auto_explain.log_buffers = on;

-- テスト実行
SELECT * FROM orders WHERE created_at >= '2026-01-01';

-- ログに実行計画が出力される

4. auto_explain ログ出力例とフィールド定義

Log — auto_explain 出力例
2026-05-29 14:32:01.123 JST [12345]: [3-1] user=appuser,db=mydb,app=myapp,client=192.168.1.10
  LOG:  duration: 2345.678 ms  plan:
        Query Text: SELECT u.user_id, u.name, COUNT(o.order_id)
                    FROM users u LEFT JOIN orders o ON u.user_id = o.user_id
                    WHERE u.created_at >= '2025-01-01'
                    GROUP BY u.user_id ORDER BY 3 DESC LIMIT 100
        Hash Join  (cost=1234.56..5678.90 rows=100 width=48)
                   (actual time=123.456..2340.123 rows=100 loops=1)
          Hash Cond: (o.user_id = u.user_id)
          Buffers: shared hit=12340 read=456
          ->  Seq Scan on orders o  (cost=0.00..3210.00 rows=100000 width=16)
                                     (actual time=0.012..890.234 rows=100000 loops=1)
              Filter: (created_at >= '2025-01-01'::date)
              Rows Removed by Filter: 50000
              Buffers: shared hit=8000 read=320
          ->  Hash  (cost=567.89..567.89 rows=50000 width=32)
                     (actual time=45.678..45.678 rows=50000 loops=1)
              Buckets: 65536  Batches: 1  Memory Usage: 3456kB
              Buffers: shared hit=4340 read=136
              ->  Index Scan using users_pkey on users u
                                     (cost=0.43..567.89 rows=50000 width=32)
                                     (actual time=0.034..32.456 rows=50000 loops=1)
                  Buffers: shared hit=4340 read=136
        Planning Time: 1.234 ms
        Execution Time: 2345.678 ms
フィールド説明Oracle AWR 対応
duration: N ms クエリ実行時間(ms)。auto_explain.log_min_duration のしきい値を超えた場合に記録。 Elapsed Time
plan: auto_explain によって付加された実行計画。EXPLAIN ANALYZE の出力形式と同じ。 実行計画(SQL Plan)
Query Text 実行されたクエリのテキスト。 SQL_TEXT
Rows Removed by Filter フィルタ条件によって除外された行数。値が大きい場合は WHERE 条件に対応するインデックスの追加を検討。
Planning Time 実行計画の生成時間(ms)。 Parse / Bind
Execution Time クエリの実際の実行時間(ms)。 Elapsed Time

5. log_line_prefix の設定と定義

エスケープ出力内容説明
%tタイムスタンプ(タイムゾーン付き)ログ記録時刻。%mでミリ秒付き。
%pプロセス ID(PID)バックエンドの PID。pg_stat_activity.pid と対応。
%uデータベースユーザー名接続ユーザー。未接続は空。
%dデータベース名接続先 DB。未接続は空。
%aアプリケーション名application_name パラメータの値。
%hクライアントホストIP アドレスまたはホスト名。Unix ソケットは空。
%rクライアントホスト:ポートポート番号付きのリモートアドレス。
%lセッション内のログ行番号セッション開始からの累積行番号。
%sセッション開始タイムスタンプ接続確立時刻。
%v仮想トランザクション IDbackend_xid が割り当てられる前の内部 ID。
%xトランザクション ID(XID)トランザクション開始後に割り当てられる XID。
%qバックグラウンドプロセスで停止以降のエスケープをバックグラウンドプロセスで出力しない。

6. csvlog / jsonlog による構造化ログ出力

postgresql.conf — csvlog / jsonlog の設定
# CSV 形式でログ出力(PostgreSQL 10+)
log_destination = 'csvlog'
logging_collector = on

# JSON 形式でログ出力(PostgreSQL 15+)
log_destination = 'jsonlog'
logging_collector = on
SQL — csvlog をテーブルにインポートして分析
-- CSVログ読み込み用テーブル(PostgreSQL マニュアルより)
CREATE TABLE postgres_log (
    log_time               timestamp(3) with time zone,
    user_name              text,
    database_name          text,
    process_id             integer,
    connection_from        text,
    session_id             text,
    session_line_num       bigint,
    command_tag            text,
    session_start_time     timestamp with time zone,
    virtual_transaction_id text,
    transaction_id         bigint,
    error_severity         text,
    sql_state_code         text,
    message                text,
    detail                 text,
    hint                   text,
    internal_query         text,
    internal_query_pos     integer,
    context                text,
    query                  text,
    query_pos              integer,
    location               text,
    application_name       text,
    backend_type           text,
    leader_pid             integer,
    query_id               bigint
);

-- CSV ログファイルをインポート
COPY postgres_log FROM '/var/log/postgresql/postgresql-2026-05-29.csv'
WITH CSV;

-- スロークエリの検索
SELECT log_time, user_name, database_name, application_name,
       REGEXP_MATCH(message, 'duration: (\d+\.?\d*) ms') AS duration_ms,
       query
FROM postgres_log
WHERE message LIKE 'duration:%'
  AND CAST(REGEXP_REPLACE(message, 'duration: (\d+\.?\d*).*', '\1') AS numeric) >= 1000
ORDER BY log_time DESC;
csvlog 列名説明Oracle AWR 対応
log_time ミリ秒精度のログ記録時刻(タイムゾーン付き)。
process_id バックエンドプロセス ID。 SID
session_id セッションを一意に識別する ID(プロセス開始時刻.PID)。
error_severity メッセージレベル。LOG(通常ログ)/ERROR/FATAL/WARNING など。
message ログメッセージ本文。スロークエリの場合 duration: N ms statement: ... 形式。 Elapsed Time / SQL_TEXT
query_id (PostgreSQL 14+)pg_stat_statements の queryid と同じハッシュ値。ログと統計ビューの突き合わせに使える。 SQL_ID
query_id でログと pg_stat_statements を紐付ける
PostgreSQL 14 以降では、csvlog/jsonlog の query_id 列が pg_stat_statements.queryid と一致します。 ログに記録された遅いクエリを pg_stat_statements の統計と突き合わせることで、 そのクエリの累積統計も確認できます。