Início / dba / Perguntas / 280466
Accepted
dcc310
Asked: 2020-11-28 12:08:24 +0800 CST

Interpretando o tempo de inicialização e planos variados para verificações de sequência do Postgres

  • 772

Ao fazer uma pergunta recente , alguns componentes misteriosos de tempo de inicialização surgiram na minha saída EXPLAIN ANALYZE. Eu estava jogando mais e descobri que o tempo de inicialização cai para perto de 0 se eu remover a WHEREcláusula regex.

Eu executei o seguinte script bash como um teste:

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

A primeira consulta retorna uma contagem de ~30 milhões e a segunda conta apenas 7 linhas. Eles estão sendo executados em uma réplica de leitura PG 12.3 no RDS com o mínimo de outras atividades. Ambas as versões levam aproximadamente a mesma quantidade de tempo, como seria de esperar. Aqui está alguma saída filtrada com 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

Então, algumas perguntas:

  1. O que entra nesse componente de inicialização do "tempo real" na verificação de regex e por que ele é muito maior? (10-20s vs 0-1s)

  2. Embora "custo" e "tempo" não sejam unidades comparáveis, o planejador parece pensar que o custo inicial deve ser 0 em todos os casos - está sendo enganado?

  3. Por que as estratégias parecem diferentes? Ambos os planos mencionam Partial Aggregate, mas a consulta regex diz que as linhas reais são 2, mas a versão simples diz que as linhas reais são ~ 10 milhões (acho que isso é algum tipo de média entre 2 trabalhadores e 1 líder, totalizando ~ 30 milhões). Se eu tivesse que implementar isso sozinho, provavelmente somaria os resultados de várias count(*)operações, em vez de mesclar linhas e contar - os planos indicam exatamente como está fazendo isso?

Então não escondo nada, abaixo estão as versões completas do plano de consulta para cada um:


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)
postgresql explain

1 respostas

  1. Best Answer

    1. O segredo está no Rows Removed by Filter: 10115028:

      A varredura sequencial leva 17 segundos para localizar e retornar a primeira linha de resultado.

    2. O otimizador não tem ideia de quanto tempo leva até que a primeira linha passe pelo filtro. Como não faz diferença para a qualidade do plano, apenas define o custo inicial como 0.

    3. Ambos os planos funcionam da mesma forma: cada um dos três processos varre um terço da tabela e conta as linhas (a Partial Aggregateque retorna 1 linha). No primeiro caso, 10 milhões de linhas são contadas por cada trabalhador.

      Esses três números são reunidos e somados no Finalize Aggregatepalco.

    • 3

relate perguntas