Postgresseqスキャンの起動時間とさまざまな計画の解釈

Nov 28 2020

尋ねるでは最近の質問を、いくつかの神秘的な起動時間のコンポーネントが私のANALYZE EXPLAIN出力に思い付きました。さらに遊んでいたところ、正規表現WHERE句を削除すると、起動時間が0近くに低下することがわかりました。

テストとして次のbashスクリプトを実行しました。

for i in $(seq 1 10) do if (( $RANDOM % 2 == 0 ))
    then
        echo "Doing plain count"
        psql -e -c "EXPLAIN ANALYZE SELECT count(*) FROM ui_events_v2"
    else
        echo "Doing regex count"
        psql -e -c "EXPLAIN ANALYZE SELECT count(*) FROM ui_events_v2 WHERE page ~ 'foo'"
    fi
done

最初のクエリは最大3,000万のカウントを返し、2番目のクエリは7行のみをカウントします。これらは、RDSのPG 12.3リードレプリカで実行されており、他のアクティビティは最小限に抑えられています。どちらのバージョンも、予想どおり、ほぼ同じ時間がかかります。これは、以下でフィルタリングされた出力grepです。

Doing plain count
               ->  Parallel Seq Scan on ui_events_v2  (cost=0.00..3060374.07 rows=12632507 width=0) (actual time=0.086..38622.215 rows=10114306 loops=3)
Doing regex count
               ->  Parallel Seq Scan on ui_events_v2  (cost=0.00..3091955.34 rows=897 width=0) (actual time=16856.679..41398.062 rows=2 loops=3)
Doing plain count
               ->  Parallel Seq Scan on ui_events_v2  (cost=0.00..3060374.07 rows=12632507 width=0) (actual time=0.162..39454.499 rows=10114306 loops=3)
Doing plain count
               ->  Parallel Seq Scan on ui_events_v2  (cost=0.00..3060374.07 rows=12632507 width=0) (actual time=0.036..39213.171 rows=10114306 loops=3)
Doing regex count
               ->  Parallel Seq Scan on ui_events_v2  (cost=0.00..3091955.34 rows=897 width=0) (actual time=12711.308..40015.734 rows=2 loops=3)
Doing plain count
               ->  Parallel Seq Scan on ui_events_v2  (cost=0.00..3060374.07 rows=12632507 width=0) (actual time=0.244..39277.683 rows=10114306 loops=3)
Doing regex count
^CCancel request sent

だから、いくつかの質問:

  1. 正規表現スキャンの「実際の時間」のこのスタートアップコンポーネントには何が入りますか、そしてなぜそれがそれほど大きいのですか?(10-20秒対0-1秒)

  2. 「コスト」と「時間」は比較可能な単位ではありませんが、プランナーは、起動コストはすべての場合で0であるべきだと考えているようです-それはだまされていますか?

  3. なぜ戦略が違うように見えるのですか?両方の計画で言及されてPartial Aggregateいますが、正規表現クエリでは実際の行は2であると示されていますが、プレーンバージョンでは実際の行は約1,000万であると示されています(これは2人のワーカーと1人のリーダーの間の平均で、合計で約3,000万になると思います)。これを自分で実装する必要がある場合はcount(*)、行をマージしてカウントするのではなく、おそらくいくつかの操作の結果を合計します-計画はそれをどの程度正確に行っているかを示していますか?

だから私は何も隠しません、以下はそれぞれのクエリプランの完全なバージョンです:


EXPLAIN ANALYZE SELECT count(*) FROM ui_events_v2
                                                                       QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------
 Finalize Aggregate  (cost=3093171.59..3093171.60 rows=1 width=8) (actual time=39156.499..39156.499 rows=1 loops=1)
   ->  Gather  (cost=3093171.37..3093171.58 rows=2 width=8) (actual time=39156.356..39157.850 rows=3 loops=1)
         Workers Planned: 2
         Workers Launched: 2
         ->  Partial Aggregate  (cost=3092171.37..3092171.38 rows=1 width=8) (actual time=39154.405..39154.406 rows=1 loops=3)
               ->  Parallel Seq Scan on ui_events_v2  (cost=0.00..3060587.90 rows=12633390 width=0) (actual time=0.033..38413.690 rows=10115030 loops=3)
 Planning Time: 7.968 ms
 Execution Time: 39157.942 ms
(8 rows)


EXPLAIN ANALYZE SELECT count(*) FROM ui_events_v2 WHERE page ~ 'foo'
                                                                   QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------
 Finalize Aggregate  (cost=3093173.83..3093173.84 rows=1 width=8) (actual time=39908.495..39908.495 rows=1 loops=1)
   ->  Gather  (cost=3093173.61..3093173.82 rows=2 width=8) (actual time=39908.408..39909.848 rows=3 loops=1)
         Workers Planned: 2
         Workers Launched: 2
         ->  Partial Aggregate  (cost=3092173.61..3092173.62 rows=1 width=8) (actual time=39906.317..39906.318 rows=1 loops=3)
               ->  Parallel Seq Scan on ui_events_v2  (cost=0.00..3092171.37 rows=897 width=0) (actual time=17250.058..39906.308 rows=2 loops=3)
                     Filter: (page ~ 'foo'::text)
                     Rows Removed by Filter: 10115028
 Planning Time: 0.803 ms
 Execution Time: 39909.921 ms
(10 rows)

回答

3 LaurenzAlbe Nov 28 2020 at 03:30
  1. 秘密はにありRows Removed by Filter: 10115028ます:

    最初の結果行を見つけて返すには、シーケンシャルスキャンに17秒かかります。

  2. オプティマイザーは、最初の行がフィルターを通過するまでにかかる時間を知りません。プランの品質に影響はないため、起動コストを0に設定するだけです。

  3. どちらのプランも同じように機能します。3つのプロセスはそれぞれ、テーブルの3分の1をスキャンし、行をカウントします(Partial Aggregate1行を返します)。最初のケースでは、1,000万行が各ワーカーによってカウントされます。

    これらの3つの数字は、Finalize Aggregateステージで収集され、合計されます。