2
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

Day 19

PostgreSQL Advent Calendar 2025

@jri_narita(成田 裕一郎)

auto_explain パラメータ変更🐘

2
Last updated at Posted at 2025-12-18

はじめに

auto_explain を使用すると、過去に実行した SQL のその時の実行計画を確認することが可能となり、SQLチューニングや SQL の性能トラブル対応などで非常に有用です。
auto_explain で設定可能な各種パラメータの、変更前後の出力の違いなどをまとめます。
なお、利用した PostgreSQL のバージョンは 17 です。

auto_explain.log_analyze

実行計画をログに出力する際、実行計画に加えて実行統計も出力するようになります。(デフォルト：OFF)

OFF
2025-12-15 05:48:47.701 UTC [37852] LOG:  duration: 4778.940 ms  plan:
        Query Text: SELECT bid, COUNT(*) AS accounts, AVG(abalance)::numeric(12,2) AS avg_bala
nce, PERCENTILE_CONT(0.9) WITHIN GROUP (ORDER BY abalance) AS p90_balance FROM pgbench_account
s GROUP BY bid ORDER BY bid;
        GroupAggregate  (cost=1700050.83..1850052.58 rows=100 width=36)
          Group Key: bid
          ->  Sort  (cost=1700050.83..1725050.83 rows=10000000 width=8)
                Sort Key: bid
                ->  Seq Scan on pgbench_accounts  (cost=0.00..263935.00 rows=10000000 width=8)
ON
2025-12-15 05:49:38.549 UTC [37852] LOG:  duration: 5991.423 ms  plan:
        Query Text: SELECT bid, COUNT(*) AS accounts, AVG(abalance)::numeric(12,2) AS avg_bala
nce, PERCENTILE_CONT(0.9) WITHIN GROUP (ORDER BY abalance) AS p90_balance FROM pgbench_account
s GROUP BY bid ORDER BY bid;
        GroupAggregate  (cost=1700050.83..1850052.58 rows=100 width=36) (actual time=3548.642..5990.761 rows=100 loops=1) ★
          Group Key: bid
          ->  Sort  (cost=1700050.83..1725050.83 rows=10000000 width=8) (actual time=3522.820..4581.635 rows=10000000 loops=1) ★
                Sort Key: bid
                Sort Method: external merge  Disk: 176160kB
                ->  Seq Scan on pgbench_accounts  (cost=0.00..263935.00 rows=10000000 width=8) (actual time=0.028..1349.877 rows=10000000 loops=1) ★

auto_explain.log_buffers

バッファ使用統計の出力を制御します。(デフォルト：OFF)
EXPLAIN の BUFFERSオプションと同じです。
auto_explain.log_analyzeが ON の必要があります。

OFF
2025-12-15 05:53:21.625 UTC [37852] LOG:  duration: 7522.294 ms  plan:
        Query Text: SELECT bid, COUNT(*) AS accounts, AVG(abalance)::numeric(12,2) AS avg_bala
nce, PERCENTILE_CONT(0.9) WITHIN GROUP (ORDER BY abalance) AS p90_balance FROM pgbench_account
s GROUP BY bid ORDER BY bid;
        GroupAggregate  (cost=1700050.83..1850052.58 rows=100 width=36) (actual time=5061.991..7521.564 rows=100 loops=1)
          Group Key: bid
          ->  Sort  (cost=1700050.83..1725050.83 rows=10000000 width=8) (actual time=5032.461..6104.810 rows=10000000 loops=1)
                Sort Key: bid
                Sort Method: external merge  Disk: 176160kB
                ->  Seq Scan on pgbench_accounts  (cost=0.00..263935.00 rows=10000000 width=8) (actual time=0.025..2363.911 rows=10000000 loops=1)
ON
2025-12-15 05:53:57.539 UTC [37852] LOG:  duration: 6183.852 ms  plan:
        Query Text: SELECT bid, COUNT(*) AS accounts, AVG(abalance)::numeric(12,2) AS avg_bala
nce, PERCENTILE_CONT(0.9) WITHIN GROUP (ORDER BY abalance) AS p90_balance FROM pgbench_account
s GROUP BY bid ORDER BY bid;
        GroupAggregate  (cost=1700050.83..1850052.58 rows=100 width=36) (actual time=3646.784..6183.128 rows=100 loops=1)
          Group Key: bid
          Buffers: shared hit=743 read=163192, temp read=44038 written=44159 ★
          ->  Sort  (cost=1700050.83..1725050.83 rows=10000000 width=8) (actual time=3619.899..4694.748 rows=10000000 loops=1)
                Sort Key: bid
                Sort Method: external merge  Disk: 176160kB
                Buffers: shared hit=743 read=163192, temp read=44038 written=44159 ★
                ->  Seq Scan on pgbench_accounts  (cost=0.00..263935.00 rows=10000000 width=8)

BUFFERS
バッファの使用状況に関する情報を含めます。 具体的には、共有ブロックのヒット数、読み取り数、ダーティブロック数、書き出し数、ローカルブロックのヒット数、読み取り数、ダーティブロック数、書き出し数、一時ブロックの読み取り数、書き出し数、そして、track_io_timingが有効にされていればデータファイルブロック、ローカルブロック、一時ファイルブロックの読み取り、書き出しに掛かった時間(ミリ秒単位)が含められます。(snip)

auto_explain.log_timing

ノード毎の時間的調整情報の出力を制御します。(デフォルト：ON)
EXPLAIN の TIMINGオプションと同じです。
auto_explain.log_analyzeが ON の必要があります。

ON
2025-12-15 05:55:38.615 UTC [37852] LOG:  duration: 6039.844 ms  plan:
        Query Text: SELECT bid, COUNT(*) AS accounts, AVG(abalance)::numeric(12,2) AS avg_bala
nce, PERCENTILE_CONT(0.9) WITHIN GROUP (ORDER BY abalance) AS p90_balance FROM pgbench_account
s GROUP BY bid ORDER BY bid;
        GroupAggregate  (cost=1700050.83..1850052.58 rows=100 width=36) (actual time=3554.937..6039.150 rows=100 loops=1)
          Group Key: bid
          ->  Sort  (cost=1700050.83..1725050.83 rows=10000000 width=8) (actual time=3528.752..4613.246 rows=10000000 loops=1)
                Sort Key: bid
OFF
2025-12-15 05:57:14.500 UTC [37852] LOG:  duration: 5151.352 ms  plan:
        Query Text: SELECT bid, COUNT(*) AS accounts, AVG(abalance)::numeric(12,2) AS avg_bala
nce, PERCENTILE_CONT(0.9) WITHIN GROUP (ORDER BY abalance) AS p90_balance FROM pgbench_account
s GROUP BY bid ORDER BY bid;
        GroupAggregate  (cost=1700050.83..1850052.58 rows=100 width=36) (actual rows=100 loops=1) ★
          Group Key: bid
          ->  Sort  (cost=1700050.83..1725050.83 rows=10000000 width=8) (actual rows=10000000 loops=1) ★
                Sort Key: bid

TIMING
実際のスタートアップ時間とノードで費やされた時間が追加表示されます。(snip)

auto_explain.log_verbose

スキーマ名など詳細な情報の出力を制御します。(デフォルト：OFF)
EXPLAIN の VERBOSEオプションと同じです。

OFF
2025-12-15 05:59:13.747 UTC [37852] LOG:  duration: 4907.076 ms  plan:
        Query Text: SELECT bid, COUNT(*) AS accounts, AVG(abalance)::numeric(12,2) AS avg_bala
nce, PERCENTILE_CONT(0.9) WITHIN GROUP (ORDER BY abalance) AS p90_balance FROM pgbench_account
s GROUP BY bid ORDER BY bid;
        GroupAggregate  (cost=1700050.83..1850052.58 rows=100 width=36)
          Group Key: bid
          ->  Sort  (cost=1700050.83..1725050.83 rows=10000000 width=8)
                Sort Key: bid
                ->  Seq Scan on pgbench_accounts  (cost=0.00..263935.00 rows=10000000 width=8)
ON
        Query Text: SELECT bid, COUNT(*) AS accounts, AVG(abalance)::numeric(12,2) AS avg_bala
nce, PERCENTILE_CONT(0.9) WITHIN GROUP (ORDER BY abalance) AS p90_balance FROM pgbench_account
s GROUP BY bid ORDER BY bid;
        GroupAggregate  (cost=1700050.83..1850052.58 rows=100 width=36)
          Output: bid, count(*), (avg(abalance))::numeric(12,2), percentile_cont('0.9'::double precision) WITHIN GROUP (ORDER BY ((abalance)::double precision)) ★
          Group Key: pgbench_accounts.bid ★
          ->  Sort  (cost=1700050.83..1725050.83 rows=10000000 width=8)
                Output: bid, abalance ★
                Sort Key: pgbench_accounts.bid ★
                ->  Seq Scan on public.pgbench_accounts  (cost=0.00..263935.00 rows=10000000 width=8)
                      Output: bid, abalance ★

VERBOSE
計画についての追加情報を出力します。 具体的には、計画ツリー、スキーマ修飾テーブル、関数名内の各ノードに対して出力列リストを含めます。(snip)

auto_explain.log_format

出力形式を制御します。(デフォルト：text)

text
2025-12-15 03:12:51.121 UTC [8562] LOG:  duration: 0.045 ms  plan:
        Query Text: select * from pgbench_accounts where aid = 777;
        Index Scan using pgbench_accounts_pkey on pgbench_accounts  (cost=0.43..8.45 rows=1 wi
dth=97)
          Index Cond: (aid = 777)
xml
2025-12-15 03:13:15.399 UTC [8562] LOG:  duration: 0.044 ms  plan:
        <explain xmlns="http://www.postgresql.org/2009/explain">
          <Query-Text>select * from pgbench_accounts where aid = 777;</Query-Text>
          <Plan>
            <Node-Type>Index Scan</Node-Type>
            <Parallel-Aware>false</Parallel-Aware>
            <Async-Capable>false</Async-Capable>
            <Scan-Direction>Forward</Scan-Direction>
            <Index-Name>pgbench_accounts_pkey</Index-Name>
            <Relation-Name>pgbench_accounts</Relation-Name>
            <Alias>pgbench_accounts</Alias>
            <Startup-Cost>0.43</Startup-Cost>
            <Total-Cost>8.45</Total-Cost>
            <Plan-Rows>1</Plan-Rows>
            <Plan-Width>97</Plan-Width>
            <Index-Cond>(aid = 777)</Index-Cond>
          </Plan>
        </explain>

auto_explain.log_level

実行計画 (実行統計) をログに出力する際のログレベルを設定できます。(デフォルト：LOG)

LOG
2025-12-15 03:15:56.545 UTC [8562] LOG:  duration: 0.032 ms  plan:
        Query Text: select * from pgbench_accounts where aid = 777;
        Index Scan using pgbench_accounts_pkey on pgbench_accounts  (cost=0.43..8.45 rows=1 wi
dth=97)
          Index Cond: (aid = 777)
WARNING
2025-12-15 03:16:17.747 UTC [8562] WARNING:  duration: 0.038 ms  plan: ★
        Query Text: select * from pgbench_accounts where aid = 777;
        Index Scan using pgbench_accounts_pkey on pgbench_accounts  (cost=0.43..8.45 rows=1 wi
dth=97)
          Index Cond: (aid = 777)

負荷が不安な場合には、下記を参考に影響を極小化しましょう :smiley:

2
0
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
2
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?