Início / dba / Perguntas / 342960
Accepted
zabop
Asked: 2024-10-12 05:02:23 +0800 CST

O plano de consulta parece depender do intervalo de tempo entre a consulta e a configuração da tabela?

  • 772

Estou trabalhando com PostgreSQL 17. Como exemplo, tenho uma tabela table0com uma coluna col0, com strings geradas aleatoriamente como valores indexados por GIN . Eu uso o seguinte setup.sqlpara criar tal tabela:

create table public.table0 (
    col0 varchar(25)
);

select setseed(0.12345);

insert into table0 (col0)
select substring(md5(random()::text), 1, (2 + (random() * 14))::int)
from generate_series(1, 12345678);

create extension pg_trgm;
create index col0_gin_trgm_idx on table0 using gin (col0 gin_trgm_ops);

vacuum (full, analyze) table0;

Usar select setseed(0.12345);garante que a tabela criada seja a mesma em cada execução de setup.sql. Gostaria de observar o plano de execução para uma consulta de correspondência de string parcial simples. Para fazer isso, uso query.sql:

explain (analyze, buffers)
select * from table0 where col0 like '%abc%' limit 500;

Para minha surpresa, o plano de execução da consulta não é constante, e aparentemente depende do tempo entre a criação da tabela e a execução da consulta. Para demonstrar isso, eu crio o seguinte script bash:

#!/bin/bash

set -o errexit
set -o nounset
set -o pipefail

rm -f records.txt

for i in {1..9}; do

    docker run \
        --name postgres-db \
        --env POSTGRES_DB=postgres \
        --env POSTGRES_USER=postgres \
        --env POSTGRES_PASSWORD=mysecretpassword \
        --publish 5432:5432\
        --detach postgres

    sleep 2 # wait for docker container to start

    PGPASSWORD=mysecretpassword psql \
        --host=localhost \
        --port=5432 \
        --username=postgres \
        --dbname=postgres \
        --set=ON_ERROR_STOP=1 \
        --file=setup.sql

    sleep $((RANDOM % 10))

    PGPASSWORD=mysecretpassword psql \
        --host=localhost \
        --port=5432 \
        --username=postgres \
        --dbname=postgres \
        --set=ON_ERROR_STOP=1 \
        --file=query.sql >> records.txt

    docker rm --force postgres-db

done

Este script configura a tabela, espera uma quantidade aleatória de até 10 segundos e, em seguida, executa o acima query.sql. Ele faz isso várias vezes. Ele salva query.sqlas saídas em records.txt. Eu olhei records.txte descobri que às vezes a varredura sequencial, às vezes a varredura de índice é usada para executar a consulta . Uma cat records.txt | grep "\->"versão filtrada (via ) de records.txt:

   ->  Bitmap Heap Scan on table0  (cost=52.34..4394.93 rows=1219 width=10) (actual time=11.526..15.200 rows=500 loops=1)
         ->  Bitmap Index Scan on col0_gin_trgm_idx  (cost=0.00..52.04 rows=1219 width=0) (actual time=9.559..9.559 rows=20852 loops=1)
   ->  Seq Scan on table0  (cost=0.00..216612.01 rows=122742 width=9) (actual time=0.068..17.788 rows=500 loops=1)
   ->  Bitmap Heap Scan on table0  (cost=52.34..4394.93 rows=1219 width=9) (actual time=5.963..8.939 rows=500 loops=1)
         ->  Bitmap Index Scan on col0_gin_trgm_idx  (cost=0.00..52.04 rows=1219 width=0) (actual time=4.144..4.144 rows=20852 loops=1)
   ->  Bitmap Heap Scan on table0  (cost=52.32..4377.97 rows=1214 width=9) (actual time=7.447..11.406 rows=500 loops=1)
         ->  Bitmap Index Scan on col0_gin_trgm_idx  (cost=0.00..52.01 rows=1214 width=0) (actual time=5.594..5.594 rows=20852 loops=1)
   ->  Bitmap Heap Scan on table0  (cost=52.33..4384.75 rows=1216 width=9) (actual time=6.660..11.991 rows=500 loops=1)
         ->  Bitmap Index Scan on col0_gin_trgm_idx  (cost=0.00..52.02 rows=1216 width=0) (actual time=4.744..4.745 rows=20852 loops=1)
   ->  Bitmap Heap Scan on table0  (cost=52.34..4394.93 rows=1219 width=9) (actual time=9.153..13.563 rows=500 loops=1)
         ->  Bitmap Index Scan on col0_gin_trgm_idx  (cost=0.00..52.04 rows=1219 width=0) (actual time=7.141..7.141 rows=20852 loops=1)
   ->  Bitmap Heap Scan on table0  (cost=52.31..4374.58 rows=1213 width=10) (actual time=10.078..13.199 rows=500 loops=1)
         ->  Bitmap Index Scan on col0_gin_trgm_idx  (cost=0.00..52.01 rows=1213 width=0) (actual time=8.108..8.108 rows=20852 loops=1)
   ->  Bitmap Heap Scan on table0  (cost=52.33..4384.76 rows=1216 width=10) (actual time=7.322..12.073 rows=500 loops=1)
         ->  Bitmap Index Scan on col0_gin_trgm_idx  (cost=0.00..52.02 rows=1216 width=0) (actual time=5.526..5.527 rows=20852 loops=1)
   ->  Seq Scan on table0  (cost=0.00..216610.51 rows=245232 width=9) (actual time=0.073..23.047 rows=500 loops=1)

O completo records.txté:

                                                               QUERY PLAN                                                               
----------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=52.34..1833.55 rows=500 width=10) (actual time=11.527..15.249 rows=500 loops=1)
   Buffers: shared hit=4 read=435
   ->  Bitmap Heap Scan on table0  (cost=52.34..4394.93 rows=1219 width=10) (actual time=11.526..15.200 rows=500 loops=1)
         Recheck Cond: ((col0)::text ~~ '%abc%'::text)
         Heap Blocks: exact=428
         Buffers: shared hit=4 read=435
         ->  Bitmap Index Scan on col0_gin_trgm_idx  (cost=0.00..52.04 rows=1219 width=0) (actual time=9.559..9.559 rows=20852 loops=1)
               Index Cond: ((col0)::text ~~ '%abc%'::text)
               Buffers: shared hit=4 read=7
 Planning:
   Buffers: shared hit=51 read=13 dirtied=1
 Planning Time: 4.666 ms
 Execution Time: 15.657 ms
(13 rows)

                                                    QUERY PLAN                                                     
-------------------------------------------------------------------------------------------------------------------
 Limit  (cost=0.00..882.39 rows=500 width=9) (actual time=0.068..17.831 rows=500 loops=1)
   Buffers: shared read=1439
   ->  Seq Scan on table0  (cost=0.00..216612.01 rows=122742 width=9) (actual time=0.068..17.788 rows=500 loops=1)
         Filter: ((col0)::text ~~ '%abc%'::text)
         Rows Removed by Filter: 282649
         Buffers: shared read=1439
 Planning:
   Buffers: shared hit=55 read=9 dirtied=1
 Planning Time: 2.427 ms
 Execution Time: 17.918 ms
(10 rows)

                                                               QUERY PLAN                                                               
----------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=52.34..1833.55 rows=500 width=9) (actual time=5.965..8.988 rows=500 loops=1)
   Buffers: shared hit=4 read=435
   ->  Bitmap Heap Scan on table0  (cost=52.34..4394.93 rows=1219 width=9) (actual time=5.963..8.939 rows=500 loops=1)
         Recheck Cond: ((col0)::text ~~ '%abc%'::text)
         Heap Blocks: exact=428
         Buffers: shared hit=4 read=435
         ->  Bitmap Index Scan on col0_gin_trgm_idx  (cost=0.00..52.04 rows=1219 width=0) (actual time=4.144..4.144 rows=20852 loops=1)
               Index Cond: ((col0)::text ~~ '%abc%'::text)
               Buffers: shared hit=4 read=7
 Planning:
   Buffers: shared hit=51 read=13 dirtied=1
 Planning Time: 2.427 ms
 Execution Time: 9.234 ms
(13 rows)

                                                               QUERY PLAN                                                               
----------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=52.32..1833.89 rows=500 width=9) (actual time=7.448..11.454 rows=500 loops=1)
   Buffers: shared hit=4 read=435
   ->  Bitmap Heap Scan on table0  (cost=52.32..4377.97 rows=1214 width=9) (actual time=7.447..11.406 rows=500 loops=1)
         Recheck Cond: ((col0)::text ~~ '%abc%'::text)
         Heap Blocks: exact=428
         Buffers: shared hit=4 read=435
         ->  Bitmap Index Scan on col0_gin_trgm_idx  (cost=0.00..52.01 rows=1214 width=0) (actual time=5.594..5.594 rows=20852 loops=1)
               Index Cond: ((col0)::text ~~ '%abc%'::text)
               Buffers: shared hit=4 read=7
 Planning:
   Buffers: shared hit=81 read=13 dirtied=1
 Planning Time: 2.835 ms
 Execution Time: 11.721 ms
(13 rows)

                                                               QUERY PLAN                                                               
----------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=52.33..1833.75 rows=500 width=9) (actual time=6.662..12.059 rows=500 loops=1)
   Buffers: shared hit=4 read=435
   ->  Bitmap Heap Scan on table0  (cost=52.33..4384.75 rows=1216 width=9) (actual time=6.660..11.991 rows=500 loops=1)
         Recheck Cond: ((col0)::text ~~ '%abc%'::text)
         Heap Blocks: exact=428
         Buffers: shared hit=4 read=435
         ->  Bitmap Index Scan on col0_gin_trgm_idx  (cost=0.00..52.02 rows=1216 width=0) (actual time=4.744..4.745 rows=20852 loops=1)
               Index Cond: ((col0)::text ~~ '%abc%'::text)
               Buffers: shared hit=4 read=7
 Planning:
   Buffers: shared hit=51 read=13 dirtied=1
 Planning Time: 3.332 ms
 Execution Time: 12.511 ms
(13 rows)

                                                               QUERY PLAN                                                               
----------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=52.34..1833.55 rows=500 width=9) (actual time=9.154..13.621 rows=500 loops=1)
   Buffers: shared hit=4 read=435
   ->  Bitmap Heap Scan on table0  (cost=52.34..4394.93 rows=1219 width=9) (actual time=9.153..13.563 rows=500 loops=1)
         Recheck Cond: ((col0)::text ~~ '%abc%'::text)
         Heap Blocks: exact=428
         Buffers: shared hit=4 read=435
         ->  Bitmap Index Scan on col0_gin_trgm_idx  (cost=0.00..52.04 rows=1219 width=0) (actual time=7.141..7.141 rows=20852 loops=1)
               Index Cond: ((col0)::text ~~ '%abc%'::text)
               Buffers: shared hit=4 read=7
 Planning:
   Buffers: shared hit=51 read=13 dirtied=1
 Planning Time: 4.113 ms
 Execution Time: 14.018 ms
(13 rows)

                                                               QUERY PLAN                                                               
----------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=52.31..1833.95 rows=500 width=10) (actual time=10.079..13.249 rows=500 loops=1)
   Buffers: shared hit=4 read=435
   ->  Bitmap Heap Scan on table0  (cost=52.31..4374.58 rows=1213 width=10) (actual time=10.078..13.199 rows=500 loops=1)
         Recheck Cond: ((col0)::text ~~ '%abc%'::text)
         Heap Blocks: exact=428
         Buffers: shared hit=4 read=435
         ->  Bitmap Index Scan on col0_gin_trgm_idx  (cost=0.00..52.01 rows=1213 width=0) (actual time=8.108..8.108 rows=20852 loops=1)
               Index Cond: ((col0)::text ~~ '%abc%'::text)
               Buffers: shared hit=4 read=7
 Planning:
   Buffers: shared hit=51 read=13 dirtied=1
 Planning Time: 3.596 ms
 Execution Time: 13.682 ms
(13 rows)

                                                               QUERY PLAN                                                               
----------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=52.33..1833.75 rows=500 width=10) (actual time=7.323..12.126 rows=500 loops=1)
   Buffers: shared hit=4 read=435
   ->  Bitmap Heap Scan on table0  (cost=52.33..4384.76 rows=1216 width=10) (actual time=7.322..12.073 rows=500 loops=1)
         Recheck Cond: ((col0)::text ~~ '%abc%'::text)
         Heap Blocks: exact=428
         Buffers: shared hit=4 read=435
         ->  Bitmap Index Scan on col0_gin_trgm_idx  (cost=0.00..52.02 rows=1216 width=0) (actual time=5.526..5.527 rows=20852 loops=1)
               Index Cond: ((col0)::text ~~ '%abc%'::text)
               Buffers: shared hit=4 read=7
 Planning:
   Buffers: shared hit=51 read=13 dirtied=1
 Planning Time: 5.907 ms
 Execution Time: 12.485 ms
(13 rows)

                                                    QUERY PLAN                                                     
-------------------------------------------------------------------------------------------------------------------
 Limit  (cost=0.00..441.64 rows=500 width=9) (actual time=0.074..23.096 rows=500 loops=1)
   Buffers: shared read=1439
   ->  Seq Scan on table0  (cost=0.00..216610.51 rows=245232 width=9) (actual time=0.073..23.047 rows=500 loops=1)
         Filter: ((col0)::text ~~ '%abc%'::text)
         Rows Removed by Filter: 282649
         Buffers: shared read=1439
 Planning:
   Buffers: shared hit=51 read=13 dirtied=1
 Planning Time: 2.087 ms
 Execution Time: 23.218 ms
(10 rows)

Usei o Postgres 17 dockerizado para facilitar a reprodutibilidade.

Reiniciando o contêiner docker, executando setup.sqle então:

explain (analyze, buffers, settings)
select * from table0 where col0 like '%abc%' limit 500;

retorna:

                                                               QUERY PLAN                                                               
----------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=52.32..1833.89 rows=500 width=9) (actual time=9.476..17.923 rows=500 loops=1)
   Buffers: shared hit=4 read=435
   ->  Bitmap Heap Scan on table0  (cost=52.32..4377.97 rows=1214 width=9) (actual time=9.475..17.858 rows=500 loops=1)
         Recheck Cond: ((col0)::text ~~ '%abc%'::text)
         Heap Blocks: exact=428
         Buffers: shared hit=4 read=435
         ->  Bitmap Index Scan on col0_gin_trgm_idx  (cost=0.00..52.01 rows=1214 width=0) (actual time=7.662..7.662 rows=20852 loops=1)
               Index Cond: ((col0)::text ~~ '%abc%'::text)
               Buffers: shared hit=4 read=7
 Planning:
   Buffers: shared hit=55 read=9 dirtied=1
 Planning Time: 5.597 ms
 Execution Time: 18.334 ms
(13 rows)

No entanto, não consigo entender por que às vezes é usada uma varredura sequencial e às vezes uma varredura de índice.

Por que um plano de consulta aparentemente depende do intervalo de tempo entre a consulta e a configuração da tabela?

Abaixo abordo algumas questões que surgiram nos comentários.

Há alguma outra atividade de gravação no BD?
Eu não iniciei nenhuma, e como é apenas um contêiner que eu executo na minha máquina local, a menos que haja algum processo automatizado do qual eu não esteja ciente, não há nenhuma atividade de gravação.

O quão ocupado está seu servidor de outra forma?
Não notei nada que não esteja funcionando bem. É um Apple M1 Pro, executando MacOS Sonoma 14.5.

postgresql

1 respostas

  1. Best Answer

    Só percebi depois de analisar mais de perto sua configuração: você recria o banco de dados inteiro para cada iteração no seu loop.

    Você usa setseed()para recriar exatamente o mesmo conteúdo da tabela. Isso é bom para recriar um testbed estável. Mas setseed()só se aplica a chamadas random()e random_normal()na mesma sessão, não a ANALYZE, que coleta estatísticas com base em sua própria seleção aleatória de linhas. Portanto, variações aleatórias dentro de uma distribuição padrão são esperadas para estatísticas de coluna entre iterações. Isso se reflete em pequenas variações nas estimativas de linha nos planos de consulta.

    Recriei seu cenário e obtive 20852 do total de 12345678 linhas contendo 'abc'. Para satisfazer seu LIMIT 500, o Postgres precisa ler (12345678 / 20852) * 500 = 296031linhas em média, o que não é muito mais caro do que executar uma varredura de índice de bitmap sobre o índice GIN do trigrama. Constantes ruins do planejador podem levar o planejador de consultas ao erro se as estatísticas superestimarem a frequência do seu padrão de pesquisa apenas o suficiente.

    Solução

    Obviamente você tem hardware rápido. A configuração padrão de random_page_cost = 4é enganosa para estimativa de custo. Espero uma configuração mais realista de random_page_cost = 1.1(como sugerido no manual ) para acabar com qualquer varredura sequencial no cenário dado, pois isso quadruplica aproximadamente a estimativa de custo relativa.

    Você também pode testar com um LIMITpadrão de pesquisa substancialmente menor ou mais longo (mais seletivo), ou otimizar algumas outras configurações que tornem o uso do índice (realisticamente!) mais barato nas estimativas do planejador, ou aumentar a meta de estatísticas para a tabela (ou apenas uma coluna), conforme sugerido no manual :

    Para tabelas grandes, ANALYZEpega uma amostra aleatória do conteúdo da tabela, em vez de examinar cada linha. Isso permite que até tabelas muito grandes sejam analisadas em um pequeno período de tempo. Observe, no entanto, que as estatísticas são apenas aproximadas e mudarão ligeiramente cada vez ANALYZEque for executado, mesmo que o conteúdo real da tabela não tenha mudado. Isso pode resultar em pequenas alterações nos custos estimados do planejador mostrados por EXPLAIN. Em situações raras, esse não determinismo fará com que as escolhas de planos de consulta do planejador mudem após ANALYZEa execução. Para evitar isso, aumente a quantidade de estatísticas coletadas por ANALYZE, conforme descrito abaixo.

    Ver:

    Tudo com o mesmo efeito de que as varreduras sequenciais do caso devem desaparecer.

    Aparte 1: VACUUM (FULL, ANALYZE)é um exagero, VACUUM (ANALYZE)seria bom o suficiente (e muito mais barato) para seu banco de dados original.

    Aparte 2: Melhor ainda (e muito mais barato), crie um banco de dados "modelo" uma vez no seu cluster de BD e recrie bancos de dados idênticos (com estatísticas de coluna idênticas!) com:

    CREATE DATABASE template_db_copy TEMPLATE template_db;

    Ver:

    • 1

relate perguntas