Lição 5 · extensão ~1 hora

Ler o `EXPLAIN` a sério

Até aqui olhámos para planos de uma linha. Um plano real tem vinte, aninha-se, e tem pelo menos uma armadilha de leitura que engana toda a gente na primeira vez.

1. Objetivo

No fim consegues pegar num plano de execução de vinte linhas e dizer, em menos de um minuto, onde está o tempo — e distinguir um nó que é lento por natureza de um que é lento por uma estimativa errada a montante.

2. Recuperar

Um plano diz Index Scan using idx_x com Buffers: read=1002, e o índice tem 1005 páginas. Bom ou mau?
Resposta
Mau: varreu o índice quase todo. O filtro não bate no prefixo mais à esquerda.
Que estatística prevê quantas páginas distintas um índice vai obrigar a visitar?
Resposta
correlation, em pg_stats — mas é indício, não prova. A prova é o BUFFERS.
Qual é a diferença entre EXPLAIN e EXPLAIN ANALYZE?
Resposta
EXPLAIN só mostra o plano e as estimativas. EXPLAIN ANALYZE executa mesmo a query e acrescenta os valores reais.

🔴 EXPLAIN ANALYZE executa a query

Com um UPDATE, DELETE ou INSERT, ele faz a alteração. Para ver o plano sem a executar, envolve numa transação e desfaz:

BEGIN;
EXPLAIN (ANALYZE) DELETE FROM encomendas WHERE estado = 'cancelada';
ROLLBACK;

3. O mecanismo

Lê-se de dentro para fora, e de baixo para cima

Um plano é uma árvore escrita com indentação. Cada nó recebe linhas dos filhos, faz o seu trabalho e entrega ao pai. O nó mais indentado é o que corre primeiro; o de topo é o último.

Os números de cada nó

Campo	O que diz	O que denuncia
`rows=` vs `actual rows=`	Estimado vs real	Desencontro de ordens de grandeza → estatísticas ou correlações mal estimadas
`loops=`	Quantas vezes o nó correu	🔴 `actual time` e `rows` são por execução. O total é × `loops`
`actual time=x..y`	x = até à primeira linha; y = até à última	É acumulado: inclui os filhos. O tempo próprio é y menos o y dos filhos
`Rows Removed by Filter`	Linhas lidas e deitadas fora	Um número grande é trabalho desperdiçado — candidato a índice
`Heap Fetches`	Idas à tabela num index-only scan	Visibility map desatualizado (lição 2)
`Sort Method`	`quicksort` / `top-N heapsort` / `external merge`	`external merge Disk: NkB` = ordenou em disco → `work_mem` curto
`Buffers: hit / read`	Páginas vindas da cache / do disco	O verdadeiro medidor de I/O. Pede sempre `BUFFERS`

⚠️ A armadilha do loops

(actual time=0.001..0.001 rows=1 loops=10000) parece o nó mais rápido do plano. Na verdade correu dez mil vezes: devolveu 10 000 linhas no total e gastou ~10 ms, não 0,001 ms.

É o erro de leitura mais comum em planos com Nested Loop, e leva a procurar o problema no sítio errado. Multiplica sempre por loops antes de concluir seja o que for.

O método, em quatro perguntas

Onde está o tempo? Procura o nó cujo actual time final é próximo do total e cujos filhos são muito mais rápidos. É esse que está a gastar.
As estimativas batem certo? rows= contra actual rows=, lembrando o loops. Se não batem, corrige isso antes de mais nada.
Há trabalho desperdiçado? Rows Removed by Filter grande, Heap Fetches alto, Sort Method: external merge.
Quantas páginas? Buffers. É o único número que não mente sobre I/O — e é estável entre execuções, ao contrário do tempo.

4. Exemplo trabalhado

Um plano real, com junção, agregação e ordenação. Precisamos de uma segunda tabela:

CREATE TABLE clientes (id integer PRIMARY KEY, nome text NOT NULL, pais text NOT NULL);
INSERT INTO clientes SELECT i, 'Cliente '||i, (ARRAY['PT','ES','FR','DE','BR'])[1+(i*13)%5]
FROM generate_series(1,50000) i;
CREATE INDEX idx_ce ON encomendas (cliente_id, estado);
ANALYZE clientes; ANALYZE encomendas;

EXPLAIN (ANALYZE, BUFFERS)
SELECT c.nome, count(*) FROM clientes c
JOIN encomendas e ON e.cliente_id = c.id
WHERE c.pais = 'PT' AND e.estado = 'pendente'
GROUP BY c.nome ORDER BY count(*) DESC LIMIT 10;

Limit  (actual time=12.404..12.406 rows=10 loops=1)
  Buffers: shared hit=29347 read=1000
  ->  Sort  (actual time=12.404..12.405 rows=10 loops=1)
        Sort Key: (count(*)) DESC
        Sort Method: top-N heapsort  Memory: 25kB
        ->  HashAggregate  (actual time=12.342..12.378 rows=500 loops=1)
              Group Key: c.nome
              Batches: 1  Memory Usage: 241kB
              ->  Nested Loop  (actual time=0.013..11.774 rows=10000 loops=1)
                    Buffers: shared hit=29344 read=1000
                    ->  Seq Scan on clientes c  (actual time=0.004..2.392 rows=10000 loops=1)
                          Filter: (pais = 'PT'::text)
                          Rows Removed by Filter: 40000
                          Buffers: shared hit=319
                    ->  Index Only Scan using idx_ce on encomendas e
                          (actual time=0.001..0.001 rows=1 loops=10000)
                          Index Cond: ((cliente_id = c.id) AND (estado = 'pendente'))
                          Heap Fetches: 24
                          Buffers: shared hit=29025 read=1000
Planning Time: 0.662 ms

Passo 1 — ler a estrutura antes de ler os números

Porquê primeiro: sem saber a ordem de execução, os números não significam nada.

De dentro para fora: Seq Scan em clientes → para cada cliente encontrado, um Index Only Scan em encomendas (é isso que um Nested Loop faz) → agregar → ordenar → cortar aos 10.

Passo 2 — onde está o tempo

Total: 12,4 ms. O Nested Loop acaba aos 11,774 ms; o Seq Scan filho acaba aos 2,392. Cerca de 9,4 ms passam-se dentro do Nested Loop — ou seja, nas repetições do lado interno.

Passo 3 — o nó «mais rápido» é o mais caro

O Index Only Scan diz actual time=0.001..0.001 rows=1. Parece irrelevante. Mas diz também loops=10000:

Linhas devolvidas: 1 × 10 000 = 10 000 (bate com as do Nested Loop).
Tempo: ~0,001 × 10 000 ≈ 10 ms — praticamente o tempo todo da query.
Páginas: 30 025, num índice que tem cerca de mil. Foi lido 30 vezes, aos bocados.

✅ Diagnóstico

O problema não é nenhum nó estar mal: é a query tocar em 10 000 clientes portugueses, um a um. O Seq Scan em clientes também deitou fora 40 000 linhas (Rows Removed by Filter) — um índice em clientes(pais) pouparia isso, mas são só 2,4 ms dos 12,4.

A correção com mais efeito seria trocar o Nested Loop por um Hash Join: ler as encomendas pendentes de uma vez (são 20 000) e juntá-las por dispersão, em vez de 10 000 descidas à árvore. Se o planeador não o fizer sozinho, é sinal de estimativa errada — e volta-se à lição 3.

Passo 4 — o que não é problema aqui

Tão importante como encontrar: Sort Method: top-N heapsort Memory: 25kB — ordenou em memória e só guardou 10 elementos, que é o comportamento ótimo com LIMIT. Batches: 1 no HashAggregate — coube em memória. Heap Fetches: 24 em 10 000 execuções — o visibility map está bom. Não se mexe no que está bem.

5. Exemplo com lacunas

Completa o diagnóstico

Hash Join  (actual time=850.1..4210.7 rows=1200000 loops=1)
  ->  Seq Scan on pedidos  (actual time=0.01..310.2 rows=2000000 loops=1)
  ->  Hash  (actual time=849.8..849.8 rows=48000 loops=1)
        Buckets: 4096  Batches: 16  Memory Usage: 3400kB
        ->  Seq Scan on artigos  (actual time=0.02..95.4 rows=48000 loops=1)
              Filter: (ativo = true)
              Rows Removed by Filter: 952000

Passo 1 (completa). Que nó corre primeiro? ______ Qual é o tempo total? ______

Passo 2 (completa). O Seq Scan on artigos demorou 95 ms mas o Hash acima dele acabou aos 850 ms. Onde foram os outros ~755 ms? ______

Passo 3 (completa). Que campo denuncia a causa? ______ O que significa? ______

Passo 4 (completa). Duas correções possíveis: ______ e ______

Ver os passos em falta

Passo 1: Seq Scan on artigos (o mais indentado). Total: 4210,7 ms.

Passo 2: na construção da tabela de dispersão, que teve de ser feita por partes.

Passo 3: Batches: 16. Com Batches: 1 a tabela cabe em memória; 16 significa que não coube e o Postgres a partiu em 16 pedaços, escrevendo e relendo do disco — e obrigando a percorrer o lado grande em vários passes. É a causa dos 755 ms e parte dos 3400 ms do join.

Passo 4:

Aumentar work_mem na sessão. Se Batches passar a 1, era isso.
Índice parcial em artigos com WHERE ativo = true: os Rows Removed by Filter: 952000 dizem que 95% do que se leu foi deitado fora. Um índice parcial evita ler os inativos de todo — lição 6.

⭐ Repara que a leitura correta apontou para work_mem e para um índice na tabela pequena. Quem olhasse só para «2 000 000 de linhas em pedidos» iria indexar a tabela grande — que aqui não é o problema.

6. Erros comuns

A ideia errada	Como se reconhece	O que é mesmo
«Este nó é rápido: 0,001 ms»	Ignorar `loops=`	Multiplica por `loops`. 0,001 × 10 000 = 10 ms, que era a query toda
«O nó de topo é o que demora»	Culpar o `Limit` ou o `Sort`	`actual time` é acumulado: inclui os filhos. O tempo próprio é a diferença
«`Planning Time` é irrelevante»	Nunca olhar para ele	Numa query de 0,5 ms com 1,5 ms de planeamento, o planeamento é o problema — e resolve-se com `PREPARE`
Correr `EXPLAIN ANALYZE` num `DELETE`	Descobrir tarde de mais	Ele executa. `BEGIN; … ROLLBACK;`
Comparar tempos entre execuções	«Agora deu 2 ms, melhorou»	A segunda execução tem a cache quente. Compara `Buffers`, que é estável, não `Execution Time`
Otimizar o nó mais chamativo	Indexar a tabela com mais linhas	Otimiza-se onde está o tempo. Muitas vezes é a tabela pequena, ou um `work_mem` curto

7. Praticar

●○○

E1 — quanto tempo, afinal?

Um nó diz (actual time=0.003..0.004 rows=2 loops=45000). Quantas linhas produziu ao todo, e quanto tempo gastou aproximadamente?

Solução

90 000 linhas (2 × 45 000) e ~180 ms (0,004 × 45 000). Se a query inteira demora 200 ms, este nó «de 0,004 ms» é 90% do tempo.

●●○

E2 — código que corre: provocar uma ordenação em disco

Força um Sort Method: external merge na base de treino baixando o work_mem, e depois repara-o. Mede os dois casos.

Solução

SET work_mem = '64kB';
EXPLAIN (ANALYZE, BUFFERS) SELECT * FROM encomendas ORDER BY total_cents;
-- Sort Method: external merge  Disk: 15792kB   (e cada worker paralelo o seu)

SET work_mem = '256MB';
EXPLAIN (ANALYZE, BUFFERS) SELECT * FROM encomendas ORDER BY total_cents;
-- Sort Method: quicksort  Memory: 79342kB
RESET work_mem;

O Disk: na primeira versão são ficheiros temporários escritos e relidos. Duas notas que valem mais do que o exercício:

work_mem é por operação de ordenação ou dispersão, não por query nem por ligação. Uma query com três Sorts e paralelismo pode usar várias vezes o valor configurado — e é por isso que subi-lo globalmente é perigoso. Sobe-se na sessão, ou para a query.
Com um LIMIT pequeno o Postgres usa top-N heapsort e guarda só N elementos: muitas ordenações «grandes» nunca precisam de memória nenhuma.

●●●

E3 — diagnóstico completo

Reproduz o exemplo trabalhado na tua base e responde com medições:

Quantas páginas lê o Index Only Scan ao todo, e quantas páginas tem o índice?
Cria um índice em clientes(pais). O plano muda? O tempo melhora quanto?
Força um Hash Join com SET enable_nestloop = off. Ficou melhor ou pior? E o que é que isso te diz sobre a decisão do planeador?

Solução

~30 025 páginas, num índice de ~1000. Foi percorrido ~30 vezes em fragmentos — normal num Nested Loop com 10 000 iterações, e é aí que está o tempo.
O Seq Scan on clientes passa a Bitmap Heap Scan e poupa os Rows Removed by Filter: 40000. Ganham-se ~2 ms em 12,4 — real mas pequeno. É a lição de não otimizar o que salta à vista sem ver onde está o tempo.
Depende da tua máquina e da cache — e é esse o ponto do exercício. Se o Hash Join ficar melhor, o planeador estava a subestimar o custo do Nested Loop, provavelmente por estimativas de linhas; verifica rows= contra actual rows= em cada nó. Se ficar pior, ele tinha razão. 🔴 Em qualquer dos casos, RESET enable_nestloop; — é diagnóstico, não correção.

8. Quiz

9. Explica por palavras tuas

Explica a alguém como se encontra «onde está o tempo» num plano de execução, se os tempos são todos acumulados e alguns nós correm milhares de vezes. Sem usar «nó», «acumulado» nem «loops». Descreve o procedimento que tu seguirias.

Porque é que comparar Execution Time entre duas execuções é enganador, e o que usarias em vez disso? Diz também em que situação o tempo é a métrica certa.

Entregar

Texto da entrega (só aparece se a cópia automática falhar)

Guardar em topicos/indices-btree-sql/respostas/AAAA-MM-DD.md.

10. Resumo

Lê-se de dentro para fora. actual time é acumulado: o tempo próprio é a diferença para os filhos.
🔴 loops=: tempo e linhas são por execução. Multiplica antes de concluir.
Quatro perguntas: onde está o tempo · as estimativas batem · há trabalho desperdiçado · quantas páginas.
Sinais que apontam para correções concretas: Rows Removed by Filter (índice, talvez parcial) · Batches > 1 e external merge (work_mem) · Heap Fetches (VACUUM) · lossy (work_mem).
Compara Buffers entre versões, nunca Execution Time — e EXPLAIN ANALYZE num DELETE apaga mesmo.

11. Fontes

Documentação do PostgreSQL 17 — Using EXPLAIN. using-explain.html — fonte primária, incluindo o aviso explícito de que ANALYZE executa a query e a explicação de que os tempos são acumulados e por execução. Porquê: é o texto mais útil da documentação inteira. 🌐 Verificado a 2026-09-15
Documentação do PostgreSQL 17 — EXPLAIN (referência do comando). sql-explain.html — todas as opções: BUFFERS, SETTINGS, WAL, FORMAT JSON. 🌐 Verificado a 2026-09-15
Documentação do PostgreSQL 17 — Resource Consumption (work_mem). runtime-config-resource.html — confirma que o limite é por operação, e não por query nem por ligação. 🌐 Verificado a 2026-09-15
Ferramenta recomendada — explain.dalibo.com, que desenha o plano e destaca os nós caros. Porquê: útil em planos grandes. Aviso: colar planos de produção num site é enviar nomes de tabelas e de colunas para fora — confirma a política da tua organização antes. 🌐 Verificado a 2026-09-15
O plano do exemplo trabalhado foi corrido em PostgreSQL 17.11 sobre preparar.sql mais a tabela clientes criada acima. ✅ Corrido a 2026-09-15

Ler o EXPLAIN a sério

1. Objetivo

2. Recuperar

3. O mecanismo

Lê-se de dentro para fora, e de baixo para cima

Os números de cada nó

O método, em quatro perguntas

4. Exemplo trabalhado

Passo 1 — ler a estrutura antes de ler os números

Passo 2 — onde está o tempo

Passo 3 — o nó «mais rápido» é o mais caro

Passo 4 — o que não é problema aqui

5. Exemplo com lacunas

Completa o diagnóstico

6. Erros comuns

7. Praticar

E1 — quanto tempo, afinal?

E2 — código que corre: provocar uma ordenação em disco

E3 — diagnóstico completo

8. Quiz

9. Explica por palavras tuas

Entregar

10. Resumo

11. Fontes

Ler o `EXPLAIN` a sério