🐘
クエリのパフォーマンスを Azure Database for PostgreSQL の クエリ ストア を使って調査する
クエリのパフォーマンスを Azure Database for PostgreSQL の クエリ ストア を使って調査する
PostgreSQL に限らず、リレーショナルデータベースにおけるパフォーマンスチューニングに、クエリ実行に関する調査は必要不可欠です。具体的には、個々のクエリの実行時間を洗い出し、実行プランを把握し、待機イベント/待機統計等を調査してクエリの実行を阻害している要因を特定します。
本記事では、Azure Database for PostgreSQL において、上記をどのように行うのかを、 (Azure ではなく) PostgreSQL 自体が提供する方法と比較し、例を交えて解説します。
前提
- PostgreSQL が提供する方法としては、主に
pg_stat_statementsを使用します。 - Azure Database for PostgreSQL が提供する方法としては、
クエリ ストアを使用します。 -
psqlコマンドの利用を想定します。 -
\x onを実行し、実行結果を見やすくしておきます。
クエリの実行時間
PostgreSQL
pg_stat_statements を使用します。
実行例
SELECT query, calls, total_time, rows
FROM pg_stat_statements
ORDER BY total_time DESC
LIMIT 1;
(0 rows)
Azure Database for PostgreSQL
クエリ ストア を使用します。
最も実行時間が長いクエリを特定する例:
SELECT DISTINCT query_sql_text, total_time
FROM query_store.query_texts_view AS qtv
INNER JOIN query_store.runtime_stats_view AS rsv
ON qtv.query_text_id = rsv.query_id
ORDER BY total_time DESC
LIMIT 1;
-[ RECORD 1 ]--+-----------------------------------------------------
query_sql_text | SELECT pg_start_backup('2022-02-3--09-06-16', false)
total_time | 12269.1204319065
クエリの実行プラン
PostgreSQL
EXPLAIN または EXPLAIN ANALYZE を使用します。
EXPLAIN の例
EXPLAIN
SELECT DISTINCT query_sql_text, total_time
FROM query_store.query_texts_view AS qtv
INNER JOIN query_store.runtime_stats_view AS rsv
ON qtv.query_text_id = rsv.query_id
ORDER BY total_time DESC
LIMIT 1;
-[ RECORD 1 ]-----------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | Limit (cost=513.75..513.75 rows=1 width=282)
-[ RECORD 2 ]-----------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Sort (cost=513.75..516.25 rows=1000 width=282)
-[ RECORD 3 ]-----------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | Sort Key: pivoted_runtime_stats_values.total_time DESC
-[ RECORD 4 ]-----------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> HashAggregate (cost=498.75..508.75 rows=1000 width=282)
-[ RECORD 5 ]-----------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | Group Key: pivoted_runtime_stats_values.total_time, query_texts.query_sql_text
-[ RECORD 6 ]-----------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Hash Join (cost=478.39..493.75 rows=1000 width=282)
-[ RECORD 7 ]-----------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | Hash Cond: (runtime_stats_entries.query_id = query_texts.query_text_id)
-[ RECORD 8 ]-----------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Hash Join (cost=468.09..480.72 rows=1000 width=16)
-[ RECORD 9 ]-----------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | Hash Cond: (pivoted_runtime_stats_values.runtime_stats_entry_id = runtime_stats_entries.runtime_stats_entry_id)
-[ RECORD 10 ]----------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Function Scan on crosstab pivoted_runtime_stats_values (cost=0.00..10.00 rows=1000 width=16)
-[ RECORD 11 ]----------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Hash (cost=278.04..278.04 rows=15204 width=16)
-[ RECORD 12 ]----------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Seq Scan on runtime_stats_entries (cost=0.00..278.04 rows=15204 width=16)
-[ RECORD 13 ]----------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Hash (cost=9.02..9.02 rows=102 width=282)
-[ RECORD 14 ]----------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Seq Scan on query_texts (cost=0.00..9.02 rows=102 width=282)
EXPLAIN ANALYZE の例
EXPLAIN ANALYZE
SELECT DISTINCT query_sql_text, total_time
FROM query_store.query_texts_view AS qtv
INNER JOIN query_store.runtime_stats_view AS rsv
ON qtv.query_text_id = rsv.query_id
ORDER BY total_time DESC
LIMIT 1;
-[ RECORD 1 ]-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | Limit (cost=513.75..513.75 rows=1 width=282) (actual time=531.545..531.548 rows=1 loops=1)
-[ RECORD 2 ]-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Sort (cost=513.75..516.25 rows=1000 width=282) (actual time=531.544..531.547 rows=1 loops=1)
-[ RECORD 3 ]-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | Sort Key: pivoted_runtime_stats_values.total_time DESC
-[ RECORD 4 ]-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | Sort Method: top-N heapsort Memory: 26kB
-[ RECORD 5 ]-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> HashAggregate (cost=498.75..508.75 rows=1000 width=282) (actual time=528.541..529.800 rows=8405 loops=1)
-[ RECORD 6 ]-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | Group Key: pivoted_runtime_stats_values.total_time, query_texts.query_sql_text
-[ RECORD 7 ]-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Hash Join (cost=478.39..493.75 rows=1000 width=282) (actual time=507.635..520.945 rows=15647 loops=1)
-[ RECORD 8 ]-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | Hash Cond: (runtime_stats_entries.query_id = query_texts.query_text_id)
-[ RECORD 9 ]-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Hash Join (cost=468.09..480.72 rows=1000 width=16) (actual time=507.535..518.182 rows=15647 loops=1)
-[ RECORD 10 ]----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | Hash Cond: (pivoted_runtime_stats_values.runtime_stats_entry_id = runtime_stats_entries.runtime_stats_entry_id)
-[ RECORD 11 ]----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Function Scan on crosstab pivoted_runtime_stats_values (cost=0.00..10.00 rows=1000 width=16) (actual time=504.439..511.154 rows=15647 loops=1)
-[ RECORD 12 ]----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Hash (cost=278.04..278.04 rows=15204 width=16) (actual time=3.066..3.066 rows=15647 loops=1)
-[ RECORD 13 ]----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | Buckets: 16384 Batches: 1 Memory Usage: 862kB
-[ RECORD 14 ]----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Seq Scan on runtime_stats_entries (cost=0.00..278.04 rows=15204 width=16) (actual time=0.019..1.573 rows=15647 loops=1)
-[ RECORD 15 ]----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Hash (cost=9.02..9.02 rows=102 width=282) (actual time=0.094..0.095 rows=108 loops=1)
-[ RECORD 16 ]----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | Buckets: 1024 Batches: 1 Memory Usage: 42kB
-[ RECORD 17 ]----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | -> Seq Scan on query_texts (cost=0.00..9.02 rows=102 width=282) (actual time=0.012..0.053 rows=108 loops=1)
-[ RECORD 18 ]----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | Planning Time: 0.332 ms
-[ RECORD 19 ]----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
QUERY PLAN | Execution Time: 536.642 ms
Azure Database for PostgreSQL
本記事執筆時点においては、Azure Database for PostgreSQL が独自に提供する方法はありません。
query_store.qs_view に plan_id があり、実行プランの ID を取得できりようになってはいますが、まだ利用できません (値が入っていません)。
したがって、通常の PostgreSQL と同様、 EXPLAIN / EXPLAIN ANALYZE を使用します。
待機イベント
PostgreSQL
pg_stat_activity を使用します。
実行例
SELECT pid, wait_event_type, wait_event
FROM pg_stat_activity
WHERE wait_event IS NOT NULL;
(0 rows)
Azure Database for PostgreSQL
クエリ ストア を使用します。
最も実行時間が長いクエリの待機イベントを特定する例
SELECT DISTINCT pwsv.start_time, pwsv.end_time, qv.total_time, pwsv.event_type, pwsv.event, qtv.query_sql_text
FROM query_store.pgms_wait_sampling_view AS pwsv
INNER JOIN query_store.qs_view AS qv
ON pwsv.query_id = qv.query_id
INNER JOIN query_store.query_texts_view AS qtv
ON pwsv.query_id = qtv.query_text_id
ORDER BY total_time DESC
LIMIT 1;
-[ RECORD 1 ]--+-----------------------------------------------------
start_time | 2022-07-13 15:59:44+00
end_time | 2022-07-13 16:14:44+00
total_time | 12269.1204319065
event_type | IO
event | WALWrite
query_sql_text | SELECT pg_start_backup('2022-02-3--09-06-16', false)
まとめ
Azure Database for PostgreSQL において、クエリのパフォーマンスに関する調査をどのように行うのかを、PostgreSQL の標準的な方法と比較し、例を交えて解説しました。
クエリ ストア ではかなり詳細な情報を得ることができます。また、上記で挙げた SQL はほんの一例です。膨大なデータを活用し、パフォーマンスの改善に役立てていきましょう。
See also
全般
- クエリ ストア - Azure Database for PostgreSQL - Single Server | Microsoft Docs
- チューニング ～SQLチューニングの概要～｜PostgreSQLインサイド : 富士通
クエリの実行時間
- スロークエリの分析 | Let's POSTGRES
- スロークエリの確認方法：PostgreSQL編 - pTune.jp
- » pg_stat_statements を使って遅い SQL を見つけ出そう – PowerGres 体験記 第 5 回 | 技術情報 | PowerGres
- PostgreSQL の pg_stat_statements で総実行時間の長いクエリランキングを取得する - ablog
Discussion