シェア

はじめに

データベースを利用したアプリケーションを扱う場合、パフォーマンス管理は継続的なタスクです。実行速度の遅いクエリは、タイムアウトを引き起こしたり、ユーザーエクスペリエンスを低下させたり、より多くのリソースを使用したり、データベースの支払い方法によっては予算に影響を与えたりする可能性があります。これらの問題により、問題のあるクエリを特定して修正できるように、データベースのパフォーマンス特性を理解することが重要になります。

このガイドでは、PostgreSQL データベースでパフォーマンスの低いクエリを特定するさまざまな方法について説明します。その後、PostgreSQL のパフォーマンスを維持するために遅いクエリを修正するために使用できるさまざまな手法について説明します。

アクティブなクエリとプロセスの確認

パフォーマンスの低いクエリを追跡しようとする際に最初に確認すべき場所は、現在アクティブなクエリとプロセスのリストです。PostgreSQL は、pg_stat_activity ビューを使用してこのデータを利用できるようにします。

pg_stat_activity ビューは、PostgreSQL の累積統計システム内で利用可能なビューの 1 つです。サーバープロセスごとに 1 行が含まれており、各プロセスが現在何に取り組んでいるかを確認するのに役立ちます。

ビュー内のすべての情報を表示するには、次のように入力します。

SELECT * FROM pg_stat_activity \gx
-[ RECORD 1 ]----+-------------------------------
datid |
datname |
pid | 1963
leader_pid |
usesysid |
usename |
application_name |
client_addr |
client_hostname |
client_port |
backend_start | 2022-11-01 11:03:44.083043+01
xact_start |
query_start |
state_change |
wait_event_type | Activity
wait_event | AutoVacuumMain
state |
backend_xid |
backend_xmin |
query_id |
query |
backend_type | autovacuum launcher
-[ RECORD 2 ]----+-------------------------------
datid |
datname |
pid | 1965
leader_pid |
usesysid | 10
usename | postgres
application_name |
client_addr |
client_hostname |
client_port |
backend_start | 2022-11-01 11:03:44.083926+01
xact_start |
query_start |
state_change |
wait_event_type | Activity
wait_event | LogicalLauncherMain
state |
backend_xid |
backend_xmin |
query_id |
query |
backend_type | logical replication launcher
-[ RECORD 3 ]----+-------------------------------
datid | 13921
datname | postgres
pid | 836027
leader_pid |
usesysid | 10
usename | postgres
application_name | psql
client_addr |
client_hostname |
client_port | -1
backend_start | 2022-11-06 20:20:18.273218+01
xact_start | 2022-11-06 20:39:01.207078+01
query_start | 2022-11-06 20:39:01.207078+01
state_change | 2022-11-06 20:39:01.207088+01
wait_event_type |
wait_event |
state | active
backend_xid |
backend_xmin | 762
query_id |
query | select * from pg_stat_activity
backend_type | client backend
-[ RECORD 4 ]----+-------------------------------
datid |
datname |
pid | 1961
leader_pid |
usesysid |
usename |
application_name |
client_addr |
client_hostname |
client_port |
backend_start | 2022-11-01 11:03:44.082354+01
xact_start |
query_start |
state_change |
wait_event_type | Activity
wait_event | BgWriterHibernate
state |
backend_xid |
backend_xmin |
query_id |
query |
backend_type | background writer
-[ RECORD 5 ]----+-------------------------------
datid |
datname |
pid | 1960
leader_pid |
usesysid |
usename |
application_name |
client_addr |
client_hostname |
client_port |
backend_start | 2022-11-01 11:03:44.082065+01
xact_start |
query_start |
state_change |
wait_event_type | Activity
wait_event | CheckpointerMain
state |
backend_xid |
backend_xmin |
query_id |
query |
backend_type | checkpointer
-[ RECORD 6 ]----+-------------------------------
datid |
datname |
pid | 1962
leader_pid |
usesysid |
usename |
application_name |
client_addr |
client_hostname |
client_port |
backend_start | 2022-11-01 11:03:44.082653+01
xact_start |
query_start |
state_change |
wait_event_type | Activity
wait_event | WalWriterMain
state |
backend_xid |
backend_xmin |
query_id |
query |
backend_type | walwriter

注: 従来のセミコロン (;) の代わりに \gx 行終端シーケンスを使用すると、PostgreSQL に現在のクエリの拡張出力モードを使用するように指示します。これにより、各レコードの列と関連する値が水平方向ではなく垂直方向に表示されるため、場合によっては読みやすさが向上します。

遅いクエリを探す際に役立つ可能性のある出力には、多くのフィールドがあります。最も関連性の高いフィールドには、次のようなものがあります。

  • state: プロセスの現在の状態。 active としてリストされている行は現在実行中です。その他の状態には、新しいクライアントコマンドを待機しているプロセスの idle、トランザクションコンテキスト内でコマンドを待機しているプロセスの idle in transaction、およびステートメントがエラーを引き起こしたトランザクションの idle in transaction (aborted) が含まれます。
  • query: 最近実行されたクエリ。アクティブなプロセスの場合、これは現在実行中のクエリになります。
  • usename: プロセスに関連付けられたユーザーの名前。
  • application_name: プロセスに接続されているアプリケーションの名前。
  • datname: ユーザーが接続しているデータベースの名前。
  • wait_event: プロセスが待機しているイベントの名前 (存在する場合)。プロセスが active 状態であり、wait_event が存在する場合、クエリは現在システムの他の部分によってブロックされていることを意味します。
  • wait_event_type: プロセスが待機しているイベントのカテゴリ。
  • pid: プロセスのプロセス ID。
  • query_start: アクティブなクエリの場合、現在のクエリが開始されたタイムスタンプ。
  • xact_start: プロセスがトランザクションを実行している場合、現在のトランザクションが開始されたタイムスタンプ。

現在のコンテキストに関連する列でクエリをフィルタリングできます。役立つパターンの 1 つは、age() 関数を使用してクエリの実行時間を計算することです。たとえば

SELECT
age(clock_timestamp(), query_start),
usename,
datname,
query
FROM pg_stat_activity
WHERE
state != 'idle'
AND query NOT ILIKE '%pg_stat_activity%'
ORDER BY age desc;

これにより、アイドル状態ではないクエリの実行時間、ユーザー名、データベース、およびクエリテキストが表示されます。結果は、実行時間の長いクエリから短いクエリの順に並べ替え、この特定のクエリを結果から除外します。

同様に、アイドル状態ではなく、待機イベントが発生しているすべてのプロセスを確認できます。

SELECT
usename,
datname,
query,
wait_event_type,
wait_event
FROM pg_stat_activity
WHERE
state != 'idle'
AND query wait_event != ''

これは、システムの他の部分 (たとえば、ロック競合) のために現在進行していないクエリを確認するのに役立ちます。

その他のシステム統計を確認する

pg_stat_activity ビューは、遅いクエリを特定するために必要な情報のほとんどを提供する可能性がありますが、最適化の追加ターゲットを特定するために、他のシステム統計も確認すると役立つ場合があります。

データベース統計の表示

pg_stat_database テーブルには、各データベースに関する統計が含まれています。

SELECT * FROM pg_stat_database \gx
. . .
-[ RECORD 2 ]------------+------------------------------
datid | 13921
datname | postgres
numbackends | 1
xact_commit | 266
xact_rollback | 9
blks_read | 229
blks_hit | 11263
tup_returned | 118708
tup_fetched | 3563
tup_inserted | 0
tup_updated | 0
tup_deleted | 0
conflicts | 0
temp_files | 0
temp_bytes | 0
deadlocks | 0
checksum_failures |
checksum_last_failure |
blk_read_time | 0
blk_write_time | 0
session_time | 5303626.534
active_time | 200.906
idle_in_transaction_time | 0
sessions | 2
sessions_abandoned | 0
sessions_fatal | 0
sessions_killed | 0
stats_reset | 2022-11-06 20:20:18.279798+01
. . .

私たちの目的のために興味深い列には、次のようなものがあります。

  • blks_read: データベースで読み取られたディスクブロック数。
  • blks_hit: ディスクブロックがバッファキャッシュで見つかった回数 (ディスクからの低速な読み取りを回避)。
  • xact_commit: コミットされたトランザクション数。
  • xact_rollback: ロールバックされたトランザクション数。

Data Egret チームがブログで示しているように、これらの生の値を使用して、キャッシュヒット率などの興味深い統計を計算できます。

SELECT
datname,
100 * blks_hit / (blks_hit + blks_read) as cache_hit_ratio
FROM
pg_stat_database
WHERE
(blks_hit + blks_read) > 0;
datname | cache_hit_ratio
-----------+-----------------
| 99
postgres | 98
template1 | 99
(3 rows)

これは、最も一般的なクエリを効果的にキャッシュできるように、データベースクラスターに RAM を追加することからメリットが得られるかどうかを評価するのに役立つ貴重な情報になる可能性があります。

テーブル統計の表示

もう 1 つの役立つビューのファミリは、pg_stat_all_tablespg_stat_user_tables、および pg_stat_sys_tables です。 pg_stat_all_tables ビューはすべてのデータベースのアクセス統計を表示し、他の 2 つのビューは、テーブルがユーザーテーブルであるかシステムテーブルであるかに基づいてテーブルをフィルタリングします。

SELECT * FROM pg_stat_all_tables \gx
. . .
-[ RECORD 104 ]-----+------------------------
relid | 1262
schemaname | pg_catalog
relname | pg_database
seq_scan | 5168
seq_tup_read | 20655
idx_scan | 20539
idx_tup_fetch | 20539
n_tup_ins | 0
n_tup_upd | 0
n_tup_del | 0
n_tup_hot_upd | 0
n_live_tup | 0
n_dead_tup | 0
n_mod_since_analyze | 0
n_ins_since_vacuum | 0
last_vacuum |
last_autovacuum |
last_analyze |
last_autoanalyze |
vacuum_count | 0
autovacuum_count | 0
analyze_count | 0
autoanalyze_count | 0

これらのビューの興味深い列には、次のようなものがあります。

  • seq_scan: テーブルで実行されたシーケンシャルスキャンの数。
  • seq_tup_read: シーケンシャルスキャンから返された行数。
  • idx_scan: テーブルに対して実行されたインデックススキャンの数。
  • idx_tup_fetch: インデックスを介して取得された行数。

これらの列の数値は、インデックスのパフォーマンスと、実行しているクエリによって効果的に使用されているかどうかを評価するのに役立ちます。テーブルに多くのシーケンシャルスキャンがあることが判明した場合、最も一般的なクエリで使用できる追加のインデックスを作成することからメリットが得られる可能性があります。

インデックスヒットの表示

現在持っているインデックスに関する詳細情報が必要な場合は、pg_stat_all_indexespg_stat_user_indexes、および pg_stat_sys_indexes ビューを確認できます。

SELECT * FROM pg_stat_all_indexes \gx
. . .
-[ RECORD 6 ]-+----------------------------------------------
relid | 1249
indexrelid | 2659
schemaname | pg_catalog
relname | pg_attribute
indexrelname | pg_attribute_relid_attnum_index
idx_scan | 822
idx_tup_read | 1670
idx_tup_fetch | 1670
. . .

これらは、各インデックスの使用頻度に関する情報を提供します。 idx_scan 列は、インデックスがスキャンされた回数を示しています。 idx_tup_read 列は、スキャンによって返されたエントリ数を示し、idx_tup_fetch は、インデックススキャンによって返された行の総数を示します。

この情報は、クエリで使用されていないインデックスがある場合を理解するのに役立ちます。これらのインデックスを特定したら、インデックスを利用するようにクエリを書き換えるか、未使用のインデックスを削除して書き込みパフォーマンスを向上させることができます。

ロック情報の表示

遅いクエリについて収集した情報の一部は、ロックの問題を指摘している可能性があります。現在保持されているすべてのロックに関する詳細情報を確認するには、pg_locks ビューをクエリします。

SELECT * FROM pg_locks \gx
-[ RECORD 1 ]------+----------------
locktype | relation
database | 13921
relation | 12290
page |
tuple |
virtualxid |
transactionid |
classid |
objid |
objsubid |
virtualtransaction | 3/3920
pid | 967262
mode | AccessShareLock
granted | t
fastpath | t
waitstart |
-[ RECORD 2 ]------+----------------
locktype | virtualxid
database |
relation |
page |
tuple |
virtualxid | 3/3920
transactionid |
classid |
objid |
objsubid |
virtualtransaction | 3/3920
pid | 967262
mode | ExclusiveLock
granted | t
fastpath | t
waitstart |

出力は、PostgreSQL 内のすべてのロックに関する情報を提供します。これは、個別のプロセスが同じオブジェクトの制御を要求するときに発生する可能性のある競合の問題を診断するのに役立ちます。

問題のあるロックの調査に役立つ可能性のある列には、次のようなものがあります。

  • locktype: ロック可能なオブジェクトのタイプ
  • database/relation/page/tuple: ロックされたアイテムのオブジェクト ID。データベースとリレーションの場合、これらは pg_database および pg_class で相互参照できます。
  • mode: 実装または要求されたロックモード
  • granted: ロックが付与されたかどうかを表すブール値。

スロークエリログを有効にする

実行時間の長いクエリに関する情報をより簡単に見つける 1 つの方法は、スロークエリログを有効にすることです。スロークエリログを有効にすると、PostgreSQL は、指定された時間よりも長く実行されるクエリを自動的に記録できます。これにより、調査時に実行されていない遅いクエリに関する情報を収集できます。

PostgreSQL がすでにスロークエリをログに記録しているか確認する

最初にすべきことは、スロークエリログの現在の状態を確認することです。スロークエリログがすでに有効になっている場合は、何もする必要はありません。

スロークエリログが有効になっているかどうかを確認するには、次のように入力します。

SELECT * FROM pg_settings WHERE name = 'log_min_duration_statement'\gx
-[ RECORD 1 ]---+---------------------------------------------------------------------------
name | log_min_duration_statement
setting | -1
unit | ms
category | Reporting and Logging / When to Log
short_desc | Sets the minimum execution time above which all statements will be logged.
extra_desc | Zero prints all queries. -1 turns this feature off.
context | superuser
vartype | integer
source | default
min_val | -1
max_val | 2147483647
enumvals |
boot_val | -1
reset_val | -1
sourcefile |
sourceline |
pending_restart | f

short_desc および extra_desc 列の値を確認すると、現在ログが有効になっているかどうかを評価できる情報が見つかります。 setting 列が現在 -1 に設定されているため、スロークエリログが現在有効になっていないことがわかります。

現在の状態がわかったので、必要に応じて変更できます。

PostgreSQL を構成してスロークエリをログに記録する

先に進む前に、スロークエリログは非常に便利ですが、パフォーマンスに影響を与える可能性があることに注意することが重要です。PostgreSQL は、各クエリの時間を測定し、結果をログに記録するために追加の操作を実行する必要があります。これはパフォーマンスに影響を与え、ハードドライブの容量を予期せずいっぱいにする可能性があります。

常にスロークエリをログに記録することは良い考えではないかもしれません。代わりに、問題を積極的に調査している場合は機能を有効にし、完了したら無効にします。

スロークエリをグローバルにログに記録する

それを念頭に置いて、PostgreSQL サーバーの構成ファイルを変更することで、スロークエリログをグローバルに構成できます。これらの値をインタラクティブに変更することもできますが、構成に適切なデフォルトを設定すると、後でインタラクティブに調整するのが簡単になります。

PostgreSQL の構成ファイルを開きます。現在の構成ファイルの場所は、次のように入力することで確認できます。

SHOW config_file;
config_file
-----------------------------------------
/etc/postgresql/14/main/postgresql.conf
(1 row)

ファイル内で、log_min_duration_statement 設定を検索します。上記の出力例の値が構成ファイルから読み取られた場合、機能が現在無効になっていることを示すために -1 に設定されます。ニーズに応じて調整できる関連設定も多数あります。

. . .
# Query logging configuration
#log_min_duration_statement = -1 # -1 is disabled, 0 logs all statements
# and their durations, > 0 logs only
# statements running at least this number
# of milliseconds
#log_min_duration_sample = -1 # -1 is disabled, 0 logs a sample of statements
# and their durations, > 0 logs only a sample of
# statements running at least this number
# of milliseconds;
# sample fraction is determined by log_statement_sample_rate
#log_statement_sample_rate = 1.0 # fraction of logged statements exceeding
# log_min_duration_sample to be logged;
# 1.0 logs all such statements, 0.0 never logs
#log_transaction_sample_rate = 0.0 # fraction of transactions whose statements
# are logged regardless of their duration; 1.0 logs all
# statements from all transactions, 0.0 never logs
. . .

現在、log_min_duration_statement 設定はコメントアウトされており、現在の値はデフォルト値を表す -1 に設定されています。他の設定はファイル内で適切にコメントされており、すべてのステートメントをログに記録するのではなく、最小値を超えるステートメントをサンプリングできます。最後の設定では、トランザクション内で発生するステートメントのサンプリングも実行できます。

log_min_duration_statement のコメントを解除し、別の値を設定することで、長時間実行クエリのログ記録を有効にできます。たとえば、完了までに 5 秒以上かかるステートメントをログに記録するように 5 秒に設定できます。

log_min_duration_statement = 5s

ファイルを保存したら、PostgreSQL 内から PostgreSQL サーバーをリロードできます。

SELECT pg_reload_conf();

現在の値を再度確認することで、サーバーが新しい設定を使用していることを確認できます。

SELECT * FROM pg_settings WHERE name = 'log_min_duration_statement'\gx
-[ RECORD 1 ]---+---------------------------------------------------------------------------
name | log_min_duration_statement
setting | 5000
unit | ms
category | Reporting and Logging / When to Log
short_desc | Sets the minimum execution time above which all statements will be logged.
extra_desc | Zero prints all queries. -1 turns this feature off.
context | superuser
vartype | integer
source | configuration file
min_val | -1
max_val | 2147483647
enumvals |
boot_val | -1
reset_val | 5000
sourcefile | /etc/postgresql/14/main/postgresql.conf
sourceline | 506
pending_restart | f

これで、setting フィールドが 5000 に設定され、unit フィールドが ms に設定され、5 秒の設定が 5000 ミリ秒に変換され、適用されたことが示されます。 sourcefile 行は、この値が変更した構成ファイルから読み取られていることも確認します。

データベースごとにスロークエリをログに記録する

遅いクエリを検出する別のオプションは、スロークエリログを特定のデータベースに制限することです。 log_min_duration_statement は、前のセクションで示したようにグローバルに設定できますが、データベースレベルでも構成できます。

単一のデータベースのスロークエリログを有効にするには、ALTER DATABASE コマンドを使用します。

ALTER DATABASE helloprisma SET 'log_min_duration_statement' = 2000;
ALTER DATABASE

グローバル設定とは異なり、ALTER DATABASE コマンドを使用する場合、値はミリ秒単位の時間を表す単位のない整数である必要があることに注意してください。

データベースごとのロール設定をクエリすることで、設定が適用されたことを確認できます。

\drds
List of settings
Role | Database | Settings
------+-------------+-------------------------------
| helloprisma | log_min_duration_statement=2000
(1 row)

これにより、以前に 5 秒のしきい値に設定したグローバル設定が妨げられていないことを確認できます。

SELECT * FROM pg_settings WHERE name = 'log_min_duration_statement'\gx
-[ RECORD 1 ]---+---------------------------------------------------------------------------
name | log_min_duration_statement
setting | 5000
unit | ms
category | Reporting and Logging / When to Log
short_desc | Sets the minimum execution time above which all statements will be logged.
extra_desc | Zero prints all queries. -1 turns this feature off.
context | superuser
vartype | integer
source | configuration file
min_val | -1
max_val | 2147483647
enumvals |
boot_val | -1
reset_val | 5000
sourcefile | /etc/postgresql/14/main/postgresql.conf
sourceline | 506
pending_restart | f

スロークエリログのテスト

最小ログ記録時間を超えるステートメントを発行して、設定をテストします。

SELECT pg_sleep(10);
pg_sleep
----------
(1 row)

ログを確認すると、実行時間の長いクエリが発生したことを示すステートメントが見つかるはずです。

2022-11-11 17:58:04.719 CET [1121088] postgres@postgres STATEMENT: select sleep(10);
2022-11-11 17:58:42.635 CET [1121088] postgres@postgres LOG: duration: 10017.171 ms statement: select pg_sleep(10);

グローバル制限と特定のテーブルで異なるしきい値があるため、一方をトリガーするが他方をトリガーしないクエリ時間を使用して、それぞれが正しく適用されていることをテストできます。

たとえば、しきい値が低いデータベースに接続し、4 秒間スリープすると、ログ行がトリガーされるはずです。

\c helloprisma
SELECT pg_sleep(4);

ログには次のように表示されます。

2022-11-13 14:46:07.361 CET [1252789] postgres@helloprisma STATEMENT: alter database helloprisma set log_min_duration_statement=2s;
2022-11-13 14:53:05.027 CET [1309069] postgres@helloprisma LOG: duration: 4022.546 ms statement: select pg_sleep(4);

次に、グローバル設定のみの影響を受けるはずの別のデータベースに切り替えることができます。同じスリープステートメントでは、ログ行はトリガーされません。

\c postgres
SELECT pg_sleep(4);

新しいログ行は記録されないはずです。

結論

この記事では、PostgreSQL が利用できるようにするパフォーマンス情報の一部を表示および理解する方法について説明しました。この情報を表示すると、システムリソース、クエリパターン、構成設定のさまざまなボトルネックを把握できます。パフォーマンスの低下が発生した場合は、PostgreSQL が提供する情報を確認して、問題のある動作の調査を開始できます。

また、スロークエリログを使用して、システムリソースを占有し、予想よりも長く実行されているクエリを正確に特定する方法についても説明しました。このデータを記録し、結果のログを評価することで、追加のインデックス、異なるクエリ構造、またはより効率的なクエリ設計が必要になる可能性のある場所を特定できます。これらのコストのかかる操作を特定する方法を知ることは、より機能的なデータベースを利用したアプリケーションを実行するための第一歩です。

著者について
Justin Ellingwood

Justin Ellingwood

Justin は、2013 年からデータベース、Linux、インフラストラクチャ、および開発者ツールについて執筆しています。彼は現在、妻と 2 羽のウサギと一緒にベルリンに住んでいます。彼は通常、三人称で書く必要はありません。これは関係者全員にとって安心です。