EXPLAIN が沈黙している内容と、それを語る方法

開発者が DBA に持ち込む、またはビジネス オーナーが PostgreSQL コンサルタントに持ち込む典型的な質問は、ほとんどの場合同じように聞こえます。 「データベース上でリクエストが完了するまでにこれほど時間がかかるのはなぜですか?」

従来の一連の理由:

• 非効率的なアルゴリズム
  数万のレコードにわたって複数の CTE を結合することにした場合
• 無関係な統計
  テーブル内のデータの実際の分布が、前回 ANALYZE によって収集されたものとすでに大きく異なっている場合
• リソースに「接続」する
  CPU の専用コンピューティング能力ではもはや十分ではなく、ギガバイトのメモリが常に消費されているか、ディスクがデータベースのすべての「要求」に対応できていません。
• ブロッキング 競合するプロセスから

そして、ブロックを捕らえて分析することが非常に難しい場合は、他のすべてのことが必要になります。 クエリプランを使用して取得できます。 EXPLAIN 演算子 (もちろん、すぐに説明（分析、バッファ）する方が良いです...）または auto_explain モジュール.

ただし、同じドキュメントに記載されているように、

「計画を理解するのは芸術であり、それを習得するにはある程度の経験が必要です...」

しかし、適切なツールを使用すれば、それなしでも大丈夫です。

クエリ プランは通常どのようなものですか? そんな感じ：

Index Scan using pg_class_relname_nsp_index on pg_class (actual time=0.049..0.050 rows=1 loops=1)
  Index Cond: (relname = $1)
  Filter: (oid = $0)
  Buffers: shared hit=4
  InitPlan 1 (returns $0,$1)
    ->  Limit (actual time=0.019..0.020 rows=1 loops=1)
          Buffers: shared hit=1
          ->  Seq Scan on pg_class pg_class_1 (actual time=0.015..0.015 rows=1 loops=1)
                Filter: (relkind = 'r'::"char")
                Rows Removed by Filter: 5
                Buffers: shared hit=1

またはこのように：

"Append  (cost=868.60..878.95 rows=2 width=233) (actual time=0.024..0.144 rows=2 loops=1)"
"  Buffers: shared hit=3"
"  CTE cl"
"    ->  Seq Scan on pg_class  (cost=0.00..868.60 rows=9972 width=537) (actual time=0.016..0.042 rows=101 loops=1)"
"          Buffers: shared hit=3"
"  ->  Limit  (cost=0.00..0.10 rows=1 width=233) (actual time=0.023..0.024 rows=1 loops=1)"
"        Buffers: shared hit=1"
"        ->  CTE Scan on cl  (cost=0.00..997.20 rows=9972 width=233) (actual time=0.021..0.021 rows=1 loops=1)"
"              Buffers: shared hit=1"
"  ->  Limit  (cost=10.00..10.10 rows=1 width=233) (actual time=0.117..0.118 rows=1 loops=1)"
"        Buffers: shared hit=2"
"        ->  CTE Scan on cl cl_1  (cost=0.00..997.20 rows=9972 width=233) (actual time=0.001..0.104 rows=101 loops=1)"
"              Buffers: shared hit=2"
"Planning Time: 0.634 ms"
"Execution Time: 0.248 ms"

しかし、「シートから」テキストで計画を読むのは非常に難しく、不明確です。

• ノードに表示されます サブツリーリソースごとの合計
  つまり、特定のノードの実行にかかった時間、またはテーブルからの読み取りによってディスクからデータが取得された時間を正確に把握するには、何らかの方法で一方から他方を減算する必要があります。
• ノード時間が必要です ループで乗算する
  はい、減算は「頭の中で」実行しなければならない最も複雑な操作ではありません。結局のところ、実行時間はノードの XNUMX 回の実行の平均として示されており、実行時間は数百回も存在する可能性があります。
• さて、これらすべてを総合すると、主要な質問に答えることができなくなります - それで誰が 「最も弱い環」?

これらすべてを数百人の開発者に説明しようとしたところ、外から見ると次のように見えることがわかりました。

つまり、必要なのは...

ツール

その中で、私たちは計画と要求に従って「誰が責任を負い、何をすべきか」を理解するのに役立つすべての主要なメカニズムを収集しようとしました。 あなたの経験の一部をコミュニティと共有してください。
出会って使って - Explain.tensor.ru

計画の可視化

こう見ると計画がわかりやすいでしょうか？

Seq Scan on pg_class (actual time=0.009..1.304 rows=6609 loops=1)
  Buffers: shared hit=263
Planning Time: 0.108 ms
Execution Time: 1.800 ms

そうではありません。

しかし、このように、 短縮形で主要な指標が分離されると、より明確になります。

でも計画がもっと複​​雑な場合は彼が助けに来てくれるだろう 円グラフの時間分布 ノードごと:

そうですね、最も困難な選択肢については、彼は急いで助けようとしています 進行状況チャート:

たとえば、プランに複数の実際のルートがある可能性があるという、非常に簡単な状況が存在します。

構造上の手がかり

さて、計画の全体構造とその問題点がすでにレイアウトされて表示されているのであれば、それを開発者にハイライトして「ロシア語」で説明してみてはいかがでしょうか。

私たちはすでにそのような推奨テンプレートを数十個集めています。

行ごとのクエリ プロファイラ

ここで、分析されたプランに元のクエリを重ね合わせると、次のように、個々のステートメントにどれだけの時間が費やされたかを確認できます。

...または次のようにしても:

リクエストへのパラメータの代入

リクエストをプランに「添付」するだけでなく、ログの DETAIL 行からのパラメータも「添付」した場合は、次のいずれかのオプションでリクエストをさらにコピーできます。

• クエリ内の値置換を使用する
  ベースでの直接実行とさらなるプロファイリング用

  SELECT 'const', 'param'::text;

• PREPARE/EXECUTEによる値置換あり
  パラメトリック部分を無視できる場合、たとえばパーティション化されたテーブルで作業する場合に、スケジューラの作業をエミュレートします。

  DEALLOCATE ALL;
  PREPARE q(text) AS SELECT 'const', $1::text;
  EXECUTE q('param'::text);
  

計画のアーカイブ

貼り付け、分析し、同僚と共有しましょう。 計画はアーカイブされたままになり、後で戻ることができます。 Explain.tensor.ru/archive

ただし、他の人にプランを見られたくない場合は、「アーカイブで公開しない」チェックボックスをオンにすることを忘れないでください。

次の記事では、計画を分析する際に生じる困難と決定について説明します。

出所： habr.com