すべての展開で、実行速度が遅すぎるクエリが常にいくつかあります。
実行に時間がかかりすぎるクエリを検出する方法と、クエリが遅い理由を理解する方法を確認するために読んでください。
pg_stat_statementsを使用しますか?
pg_stat_statementsは、コアPostgreSQLディストリビューションに含まれ、ほぼすべてのDBaaSプロバイダーでデフォルトで使用できる人気のある拡張機能です。これは非常に貴重であり、カスタム拡張機能をインストールせずにクエリの統計を取得する唯一の方法です。
ただし、遅いクエリの検出に関しては、いくつかの制限があります。
pg_stat_statements拡張機能は、累積を提供します サーバーによってこれまでに実行されたすべてのクエリに関する統計。クエリごとに、他の指標の中でも、実行された合計回数と、すべての実行にかかった合計時間が表示されます。
遅いクエリが発生したときに「キャッチ」するには、pg_stat_statements
のコンテンツ全体を定期的にフェッチする必要があります。 表示し、時系列データベースに保存して、実行回数を比較します。たとえば、午前10時と午前10時10分にpg_stat_statementsの内容がある場合、午前10時よりも午前10時10分で実行カウントが多いクエリを選択できます。これらのクエリでは、次を使用して、この間隔中の平均実行時間を計算できます。
(total time at 10.10 AM - total time at 10.00 AM) ÷ (total count at 10.10 AM - total count at 10.00 AM)
この平均実行時間が上限しきい値を超えた場合、アラートをトリガーしてアクションを実行できます。
これは実際にはかなりうまく機能しますが、優れた監視インフラストラクチャ、またはpgDashのような専用サービスが必要になります。
pg_stat_statementsは、クエリに渡されたバインドパラメータの値をキャプチャしません。
Postgresクエリプランナーが実行プランを選択するために推定することの1つは、条件がフィルターで除外する可能性のある行数です。たとえば、テーブルのほとんどの行にインデックス付きの列の値がある場合 country 「米国」として、計画担当者は順次スキャンを実行することを決定する場合があります whereのテーブル全体の 条項country = "US"
、およびインデックススキャンの使用を決定する場合があります country = "UK"
の場合 最初のどこから 句は、テーブル内のほとんどの行と一致することが期待されています。
クエリの実行が遅いパラメータの実際の値を知ることは、遅いクエリの問題をより迅速に診断するのに役立ちます。
より簡単な代替方法は、遅いクエリをログに記録することです。これを簡単にする他の特定のDBMSとは異なり、PostgreSQLは似たような構成設定を多数提供します。
-
log_statement
-
log_min_duration_statement
-
log_min_duration_sample
-
log_statement_sample_rate
-
log_parameter_max_length
-
log_parameter_max_length_on_error
-
log_duration
これらについては、Postgresのドキュメントで詳しく説明されています。妥当な出発点は次のとおりです:
# next line says only log queries that take longer 5 seconds
log_min_duration_statement = 5s
log_parameter_max_length = 1024
log_parameter_max_length_on_error = 1024
その結果、次のようなログが作成されます:
2022-04-14 06:17:11.462 UTC [369399] LOG: duration: 5.060 ms statement: select i.*, t."Name" as track, ar."Name" as artist
from "InvoiceLine" as i
join "Track" as t on i."TrackId" = t."TrackId"
join "Album" as al on al."AlbumId" = t."AlbumId"
join "Artist" as ar on ar."ArtistId" = al."ArtistId";
ログが多すぎる場合は、Postgresに5秒より長く実行されるクエリの50%のみをログに記録するように依頼できます:
log_min_duration_sample = 5s
log_statement_sample_rate = 0.5 # 0..1 => 0%..100%
もちろん、Postgres構成に追加する前に、これらのパラメーターの意味と意味についてのドキュメントを読んでください。設定は風変わりで直感的ではないことに注意してください。
通常、遅いクエリが発生したことを知るだけでは不十分です。また、理由を把握する必要があります。 遅かった。このため、通常、最初にクエリの実行プランを確認します。
auto_explain
は、実行を終了したばかりのクエリの実行計画をログに記録できる、もう1つのコアPostgreSQL拡張機能です(これもほとんどのDBaaSで利用できます)。ここに文書化されています。
auto_explainを有効にするには、通常、それをshared_preload_libraries
に追加します。 Postgresを再起動します。スターター構成の例は次のとおりです。
# logs execution plans of queries that take 10s or more to run
auto_explain.log_min_duration = 10s
auto_explain.log_verbose = on
auto_explain.log_settings = on
auto_explain.log_format = json
auto_explain.log_nested_statements = on
# enabling these provide more information, but have a performance cost
#auto_explain.log_analyze = on
#auto_explain.log_buffers = on
#auto_explain.log_wal = on
#auto_explain.log_timing = on
#auto_explain.log_triggers = on
これにより、プランがJSON形式でログに記録され、次のようなツールで視覚化できるようになります。
上記のすべての手法には、共通点が1つあります。それは、後にのみ実用的な出力を生成することです。 クエリの実行が終了しました。今回は非常に低速で、まだ実行が完了していないクエリを処理するために使用することはできません。
PostgreSQLサーバーへの各接続は、バックエンドによって処理されます。 、具体的にはクライアントバックエンド 。このようなバックエンドがクエリを実行しているとき、その状態はアクティブです。 。また、トランザクションを開始した可能性がありますが、その後アイドル状態になり、トランザクションのアイドルと呼ばれます。 状態。
pg_stat_activity
ここに記載されているシステムビューは、実行中のすべてのPostgresバックエンドのリストを提供します。このビューをクエリして、まだ実行中のクエリを取得できます:
SELECT client_addr, query_start, query
FROM pg_stat_activity
WHERE state IN ('active', 'idle in transaction')
AND backend_type = 'client backend';
ちなみに、サードパーティの拡張機能を使用しないと、現在バックエンドによって実行されているクエリの実行プランを知る方法はありません。
遅いクエリの実行プランに明らかな問題が示されていない場合は、競合するロックによってクエリを実行するバックエンドが遅延している可能性があります。
ロックは、さまざまな理由で、クエリの実行中に明示的または暗黙的に取得されます。 Postgresのドキュメントにはこれに関する章全体があります。
通常、待機時間の上限は、オプション lock_timeoutを使用して設定されます。 、通常はクライアント側で。クエリがロックを取得するためにこれだけ長い間待機している場合、Postgresはこのクエリの実行をキャンセルし、エラーをログに記録します:
2021-01-30 09:35:52.415 UTC [67] psql postgres testdb 172.17.0.1 ERROR: canceling statement due to lock timeout
2021-01-30 09:35:52.415 UTC [67] psql postgres testdb 172.17.0.1 STATEMENT: cluster t;
ロックタイムアウトを1分に設定したいが、ロックを30秒以上待機するクエリをログに記録するとします。これは、次を使用して行うことができます:
log_lock_waits = on
deadlock_timeout = 30s
これにより、次のようなログが作成されます:
2021-01-30 09:49:22.331 UTC [70] psql postgres testdb 172.17.0.1 LOG: process 70 still waiting for ShareLock on transaction 493 after 30009.004 ms
2021-01-30 09:49:22.331 UTC [70] psql postgres testdb 172.17.0.1 DETAIL: Process holding the lock: 68. Wait queue: 70.
2021-01-30 09:49:22.331 UTC [70] psql postgres testdb 172.17.0.1 CONTEXT: while locking tuple (0,3) in relation "t"
2021-01-30 09:49:22.331 UTC [70] psql postgres testdb 172.17.0.1 STATEMENT: select * from t for update;
deadlock_timeoutの使用 タイプミスではありません。これは、ロック待機ログメカニズムが使用する値です。理想的には、 log_min_duration_lock_waitのようなものがあったはずです。 、しかし残念ながら、そうではありません。
実際のデッドロックの場合、Postgresは deadlock_timeoutの後にデッドロックされたトランザクションを中止します 期間、および問題のあるステートメントをログに記録します。明示的な構成は必要ありません。
2021-01-30 09:55:37.724 UTC [68] psql postgres testdb 172.17.0.1 LOG: process 68 detected deadlock while waiting for ShareLock on transaction 496 after 30007.633 ms
2021-01-30 09:55:37.724 UTC [68] psql postgres testdb 172.17.0.1 DETAIL: Process holding the lock: 70. Wait queue: .
2021-01-30 09:55:37.724 UTC [68] psql postgres testdb 172.17.0.1 CONTEXT: while locking tuple (0,3) in relation "t"
2021-01-30 09:55:37.724 UTC [68] psql postgres testdb 172.17.0.1 STATEMENT: select * from t where a=4 for update;
2021-01-30 09:55:37.725 UTC [68] psql postgres testdb 172.17.0.1 ERROR: deadlock detected
2021-01-30 09:55:37.725 UTC [68] psql postgres testdb 172.17.0.1 DETAIL: Process 68 waits for ShareLock on transaction 496; blocked by process 70.
Process 70 waits for ShareLock on transaction 495; blocked by process 68.
Process 68: select * from t where a=4 for update;
Process 70: select * from t where a=0 for update;
2021-01-30 09:55:37.725 UTC [68] psql postgres testdb 172.17.0.1 HINT: See server log for query details.
2021-01-30 09:55:37.725 UTC [68] psql postgres testdb 172.17.0.1 CONTEXT: while locking tuple (0,3) in relation "t"
2021-01-30 09:55:37.725 UTC [68] psql postgres testdb 172.17.0.1 STATEMENT: select * from t where a=4 for update;
現在付与されているロックの全リストは、pg_locksシステムビューから入手できます。ただし、通常は関数pg_blocking_pids
を使用する方が簡単です。 、pg_stat_activity
と一緒に 、このように:
SELECT state, pid, pg_blocking_pids(pid), query
FROM pg_stat_activity
WHERE backend_type='client backend';
これは次のような出力を表示できます:
state | pid | pg_blocking_pids | query
---------------------+--------+------------------+-------------------------------------------------
active | 378170 | {} | SELECT state, pid, pg_blocking_pids(pid), query+
| | | FROM pg_stat_activity +
| | | WHERE backend_type='client backend';
active | 369399 | {378068} | cluster "Track";
idle in transaction | 378068 | {} | select * from "Track" for update;
(3 rows)
これは、ブロックされているバックエンドが1つ(CLUSTERステートメントを実行しているバックエンド)あり、PID 378068(SELECT..FOR UPDATEを実行したが、トランザクション内でアイドリングしている)によってブロックされていることを示します。
>