BUFFERSオプションとは

EXPLAINBUFFERSオプションを付けると、クエリの実行中に読み込んだブロック数が表示される。ANALYZEと併用することで、実行計画の各ノードがどれだけ共有バッファ(キャッシュ)を使ったかを確認できる。

EXPLAIN (ANALYZE, BUFFERS) SELECT * FROM accounts WHERE balance = 30631;

キャッシュされていないデータに対して実行すると、以下のような結果が得られる。

 Seq Scan on accounts  (cost=0.00..1886.00 rows=2 width=17) (actual time=0.004..14.179 rows=1 loops=1)
   Filter: (balance = 30631)
   Rows Removed by Filter: 99999
   Buffers: shared hit=1 read=635
 Planning:
   Buffers: shared hit=60 read=6
 Planning Time: 0.172 ms
 Execution Time: 14.200 ms

shared hitとreadの読み方

Buffers行のshared hitshared readは、共有バッファへのアクセス状況を示す。

  • hit: 共有バッファ上に既にあったブロック数
  • read: 共有バッファに無く、ディスクやOSのキャッシュから読み込んだブロック数

上記の例ではshared hit=1 read=635であり、636ブロックのほとんどが共有バッファにヒットせず読み込みが発生している。readはあくまで共有バッファに無かったブロック数であり、実際にディスクI/Oが発生したかOSのキャッシュから読み込んだかまでは区別できない。今回はコンテナ起動直後で共有バッファとOSキャッシュがいずれも空の状態のため、実質的にディスクからの読み込みが発生し、実行時間は14.200msかかっている。

同じクエリをもう一度実行すると、共有バッファに読み込んだブロックが乗っているため結果が変わる。

 Seq Scan on accounts  (cost=0.00..1886.00 rows=2 width=17) (actual time=0.004..3.903 rows=1 loops=1)
   Filter: (balance = 30631)
   Rows Removed by Filter: 99999
   Buffers: shared hit=636
 Planning:
   Buffers: shared hit=66
 Planning Time: 0.132 ms
 Execution Time: 3.923 ms

2回目の実行ではshared hit=636となり、readが発生していない。全ブロックが共有バッファ上に乗ったため、実行時間も14.200msから3.923msに短縮されている。実行計画のコストやrowsが同じクエリであっても、キャッシュの状態によって実行時間は大きく変わる。

Planning欄のBuffersは、実行計画を作成する段階で参照したpg_classpg_statisticなどのシステムカタログのバッファ使用状況を示す。

データベース全体のキャッシュヒット率を確認する

個別のクエリではなく、データベース全体のキャッシュヒット率を確認するにはpg_stat_databaseビューを使う。

SELECT
  datname,
  blks_hit,
  blks_read,
  round(100.0 * blks_hit / nullif(blks_hit + blks_read, 0), 2) AS cache_hit_ratio
FROM pg_stat_database
WHERE datname = 'postgres';
 datname  | blks_hit | blks_read | cache_hit_ratio 
----------+----------+-----------+-----------------
 postgres |   409345 |      1076 |           99.74

blks_hitは共有バッファでヒットしたブロック数、blks_readはディスクから読み込んだブロック数の累計である。一般的にキャッシュヒット率は99%程度が目安とされ、これを大きく下回る場合はshared_buffersの設定値がワーキングセットに対して小さい可能性がある。