Quando um SQL fica lento, o primeiro reflexo é abrir o plano. O problema é que o plano que costuma aparecer, seja do EXPLAIN PLAN ou de um DISPLAY_CURSOR sem coleta, mostra o que o otimizador esperava que acontecesse. Com GATHER_PLAN_STATISTICS (ou STATISTICS_LEVEL=ALL), você tem o plano de execução real: o que de fato aconteceu, linha por linha.
Escrevi este post porque recebo muito pedido de suporte com um plano anexado sem A-Rows e sem Buffers. O profissional passa horas analisando a situação com base em Cost, Rows e Time, ou seja, uma análise inteira fundamentada em números de projeção, e projeção não mostra onde o tempo foi gasto. E tem o caso clássico de quem bate o olho num TABLE ACCESS FULL com Cost alto e já aponta o culpado, sem nenhum dado real da execução. Às vezes o full scan é justamente o caminho mais barato. Coletar o plano real leva minutos e poupa horas de análise.
As 5 colunas que o EXPLAIN PLAN não mostra
| Coluna | O que mostra |
|---|---|
| Starts | Quantas vezes a operação foi iniciada na execução |
| A-Rows | Linhas reais produzidas, somando todos os starts |
| A-Time | Tempo real gasto na operação, já incluindo os filhos |
| Buffers | Leituras lógicas (blocos lidos da memória), já incluindo os filhos |
| Reads | Leituras físicas (blocos lidos do disco), já incluindo os filhos |
Ao lado delas fica o E-Rows, a estimativa do otimizador por start. O diagnóstico nasce da comparação entre E-Rows e A-Rows.
Plano estimado x plano de execução real
| Forma | Executa a query? | É o plano usado de verdade? | Números |
|---|---|---|---|
| EXPLAIN PLAN + DBMS_XPLAN.DISPLAY | Não | Não necessariamente | Todos estimados |
| DISPLAY_CURSOR sem coleta | Sim (já executou) | Sim | Todos estimados |
| DISPLAY_CURSOR com ALLSTATS LAST | Sim (já executou) | Sim | E-Rows estimado, o resto real |
O EXPLAIN PLAN não executa nada. Ele grava na PLAN_TABLE o que o otimizador planejou, e a própria referência da PLAN_TABLE descreve CARDINALITY, BYTES, COST e TIME como estimativas.
O DISPLAY_CURSOR sem coleta lê o cursor da shared pool, então o caminho é o que rodou. Mas os números continuam sendo do otimizador, ou seja, é o plano certo com os números estimados.
O DISPLAY_CURSOR com ALLSTATS LAST lê a V$SQL_PLAN_STATISTICS_ALL, que só é populada quando as estatísticas de row source foram coletadas na execução, pelo hint GATHER_PLAN_STATISTICS ou por STATISTICS_LEVEL=ALL.
Esse é o ponto central do post: um plano sem A-Rows pode até mostrar o caminho real, mas todo número dele é projeção. Ele mostra o caminho escolhido (full scan ou índice, tipo de join, ordem das tabelas) e quantas linhas o otimizador esperava. Não mostra onde o tempo foi gasto, qual operação leu mais blocos, nem se a estimativa de linhas estava certa. Procurar gargalo em Cost e Time estimados é perder tempo.
Para ter o plano real, existem quatro caminhos: o hint, o ALTER SESSION, o ALTER SYSTEM e o SQL Patch. O fluxo abaixo ajuda a escolher. Os três primeiros estão aqui.
O lab
Lab em Oracle 21c, schema de exemplo SH.
A query busca clientes da Califórnia (CA) nos Estados Unidos (country_id = 52790). O otimizador trata os dois filtros como independentes e multiplica as seletividades, sem saber que todo cliente CA já é dos EUA. Resultado: estima 1.115 linhas, e vêm 3.341.
Na sessão SQL*Plus como SH, confira o volume real:
SET LINESIZE 200
SET PAGESIZE 100
COLUMN total FORMAT 999G999G999 HEADING 'TOTAL|-'
SELECT COUNT(*) total
FROM sh.customers
WHERE cust_state_province = 'CA'
AND country_id = 52790;
Passo 1: o que o EXPLAIN PLAN mostra (e o que esconde)
Na mesma sessão SH:
SET LINESIZE 250
SET PAGESIZE 0
EXPLAIN PLAN FOR
SELECT /* LAB_XPLAN */ cust_id, cust_last_name
FROM sh.customers
WHERE cust_state_province = 'CA'
AND country_id = 52790;
SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY(format => 'TYPICAL'));Rows, Bytes, Cost (%CPU) e Time saem todos da PLAN_TABLE e são todos estimativa. O Time não foi cronometrado: é o que o otimizador calculou. No lab, o Rows veio 1.115, um terço das 3.341 linhas reais.
Passo 2: DISPLAY_CURSOR sem coleta, o caminho certo com os números estimados
Agora a query roda de verdade, sem hint nenhum. Na sessão SH:
SET SERVEROUTPUT OFF
SET LINESIZE 250
SET PAGESIZE 0
SET TERMOUT OFF
SELECT /* LAB_XPLAN_SEM */ cust_id, cust_last_name
FROM sh.customers
WHERE cust_state_province = 'CA'
AND country_id = 52790;
SET TERMOUT ON
SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL, NULL, 'ALLSTATS LAST'));O SET TERMOUT OFF só esconde as linhas quando o bloco roda como script (@arquivo.sql); colado direto no SQL*Plus, elas aparecem, sem problema para o plano. Já o SET SERVEROUTPUT OFF é obrigatório: com ele ligado, a chamada do DBMS_OUTPUT vira a última execução da sessão e o LAST mostra o plano errado.
Pedi ALLSTATS LAST, mas a execução não coletou nada. O resultado é o plano só com E-Rows, sem as colunas reais, e com a nota destacada no print. Essa nota é o jeito do Oracle dizer “você está olhando um plano sem medição”.
Passo 3: plano de execução real com GATHER_PLAN_STATISTICS
O contraponto do fluxo tem saída. Quando o SQL é da aplicação e não dá para mexer no texto da query, o mesmo hint pode ser colocado na query pelo lado do banco, com um SQL Patch no SQL_ID, sem tocar no código. Vou mostrar como fazer isso, passo a passo, num post seguido a este, que ainda será publicado.
Mesma query, agora com o hint. Na sessão SH:
SET SERVEROUTPUT OFF
SET LINESIZE 250
SET PAGESIZE 0
SET TERMOUT OFF
SELECT /*+ GATHER_PLAN_STATISTICS */ /* LAB_XPLAN_GPS */ cust_id, cust_last_name
FROM sh.customers
WHERE cust_state_province = 'CA'
AND country_id = 52790;
SET TERMOUT ON
SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL, NULL, 'ALLSTATS LAST'));O plano muda de cara: somem Bytes, Cost e Time estimados, e entram Starts, E-Rows, A-Rows, A-Time e Buffers. Na linha do TABLE ACCESS FULL, o otimizador esperava 1.115 linhas e vieram 3.341, três vezes mais, com 1.675 buffers lidos. Esse é o erro de estimativa que vimos no lab, com os dois filtros tratados como independentes, só que agora medido. A coluna Reads não apareceu porque os blocos já estavam no buffer cache.
Se quiser os números do otimizador junto, dá para somar modificadores no formato, como 'ALLSTATS LAST +COST +BYTES'.
Passo 4: STATISTICS_LEVEL=ALL na sessão, sem mexer no texto do SQL
Quando você não quer (ou não pode) colocar o hint, liga o nível de coleta só na sua sessão e devolve para o padrão no fim. O default do parâmetro é TYPICAL; o nível ALL acrescenta as estatísticas de execução do plano e de tempo do sistema operacional.
Na sessão SH, o bloco inteiro:
SET SERVEROUTPUT OFF
SET LINESIZE 250
SET PAGESIZE 0
SET TERMOUT OFF
ALTER SESSION SET STATISTICS_LEVEL = ALL;
SELECT /* LAB_XPLAN_SL */ cust_id, cust_last_name
FROM sh.customers
WHERE cust_state_province = 'CA'
AND country_id = 52790;
SET TERMOUT ON
SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL, NULL, 'ALLSTATS LAST'));
ALTER SESSION SET STATISTICS_LEVEL = TYPICAL;As colunas são as mesmas do passo 3. A diferença está na amostragem do tempo: com o hint, o Oracle usa a frequência padrão de amostragem; com STATISTICS_LEVEL=ALL, ele amostra todas as linhas. Resultado: A-Time mais preciso e overhead maior.
No print, o E-Rows já veio 3.341 e é o child 2: essa query já tinha rodado antes e, como a primeira estimativa errou feio, o Oracle reotimizou o cursor com o número real (é o statistics feedback, que cria um cursor filho novo). Numa primeira execução, você veria E-Rows 1.115, como no passo 3.
Passo 5: ALTER SYSTEM, e por que evitar
A tentação é ligar STATISTICS_LEVEL=ALL no banco inteiro e pronto. Funciona, mas o preço cai em todo mundo: a coleta vale para todas as sessões, pode ficar gravada no spfile (o SCOPE padrão é BOTH) e, em RAC, vale para todos os nós.
Se for inevitável (não dá para reproduzir o SQL e a versão não permite SQL Patch), faça numa janela combinada, só em memória e só na instância necessária. São dois comandos: um liga a coleta e o outro desliga. Como DBA, conectado no nó onde o SQL roda (em multitenant, dentro da PDB da aplicação), troque orcl1 pelo nome da sua instância (SELECT instance_name FROM v$instance).
Liga a coleta (ALL), só em memória e só nessa instância:
ALTER SYSTEM SET STATISTICS_LEVEL = ALL SCOPE = MEMORY SID = 'orcl1';Desliga a coleta assim que pegar o plano, voltando para o padrão (TYPICAL). Rode na mesma sessão onde ligou, para desligar exatamente no mesmo lugar:
ALTER SYSTEM SET STATISTICS_LEVEL = TYPICAL SCOPE = MEMORY SID = 'orcl1';Para conferir o que está ligado, na mesma instância e container:
SET LINESIZE 200
SET PAGESIZE 100
SET COLSEP '|'
COLUMN statistics_name FORMAT A40 HEADING 'ESTATISTICA|-'
COLUMN activation_level FORMAT A10 HEADING 'NIVEL|-'
COLUMN session_status FORMAT A10 HEADING 'SESSAO|-'
COLUMN system_status FORMAT A10 HEADING 'SISTEMA|-'
SELECT statistics_name, activation_level, session_status, system_status
FROM v$statistics_level
ORDER BY activation_level, statistics_name;A V$STATISTICS_LEVEL mostra cada estatística controlada pelo parâmetro, com a visão da sessão e a do sistema lado a lado.
Como ler o plano de execução real em 3 passos
Com o plano real na mão, o roteiro é sempre o mesmo:
- Ache onde a estimativa mais errou. Compare A-Rows com E-Rows x Starts, linha a linha. A linha com a maior diferença é a candidata a causa.
- Ache onde o custo de verdade aparece. Desça pelo plano olhando onde A-Time e Buffers dão o salto. Como o pai inclui os filhos, subtraia os filhos para saber quanto a operação gastou sozinha.
- Junte as duas pistas. Quando a operação que errou a estimativa é a mesma (ou alimenta a mesma) que concentra o tempo e os buffers, você achou o problema.
As seções abaixo mostram, com os prints do lab, as regras que fazem esse roteiro funcionar.
E-Rows é por start, A-Rows é total
O E-Rows é a estimativa para cada vez que a operação roda; o A-Rows soma todas as vezes. Por isso a comparação justa é A-Rows contra E-Rows multiplicado por Starts. Num nested loop, a operação de dentro roda uma vez para cada linha que vem de fora, e comparar A-Rows direto com E-Rows inventa uma diferença que não existe.
Para ver isso no lab, force um nested loop. Na sessão SH:
SET SERVEROUTPUT OFF
SET LINESIZE 250
SET PAGESIZE 0
SELECT /*+ GATHER_PLAN_STATISTICS LEADING(c) USE_NL(s) */ /* LAB_XPLAN_NL */
COUNT(*)
FROM sh.customers c
JOIN sh.sales s
ON s.cust_id = c.cust_id
WHERE c.cust_state_province = 'CA'
AND c.country_id = 52790;
SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL, NULL, 'ALLSTATS LAST'));
O NESTED LOOPS funciona como um laço: para cada cliente que sai do TABLE ACCESS FULL, o Oracle vai ao índice buscar as vendas daquele cliente. Vieram 3.341 clientes, então o INDEX RANGE SCAN, que fica do lado de dentro do NESTED LOOPS, rodou 3.341 vezes. É isso que a coluna Starts mostra.
Olhe a linha do INDEX RANGE SCAN:
| Coluna | Valor | O que significa |
|---|---|---|
| Starts | 3.341 | O índice foi acessado 3.341 vezes, uma por cliente |
| E-Rows | 130 | Estimativa para um acesso: cada cliente teria umas 130 vendas |
| A-Rows | 67.470 | Total real, somando os 3.341 acessos |
Bater o olho e comparar 130 com 67.470 dá a impressão de um erro gigante para menos. Só que o E-Rows é por acesso e o A-Rows é o total. A conta certa, passo a passo:
| Passo | O que calcular | Conta | Resultado |
|---|---|---|---|
| 1 | Estimativa por acesso | E-Rows | 130 linhas |
| 2 | Quantos acessos aconteceram | Starts | 3.341 |
| 3 | Estimativa total | 130 x 3.341 | 434.330 linhas |
| 4 | Real total | A-Rows | 67.470 linhas |
| 5 | Real por acesso | 67.470 ÷ 3.341 | cerca de 20 linhas |
| 6 | Tamanho do erro | 434.330 ÷ 67.470 | cerca de 6,4x para mais |
O otimizador esperava 130 vendas por cliente, e eram umas 20. Errou, mas para mais, e não 500 vezes para menos, como a comparação direta sugeria.
Regra de leitura: em operações do lado de dentro de um NESTED LOOPS, compare o A-Rows com E-Rows x Starts, nunca com o E-Rows sozinho. Fora do NESTED LOOPS o Starts quase sempre é 1, e aí a comparação direta funciona.
A-Time, Buffers e Reads são acumulados para cima
Cada linha do plano soma o próprio consumo com o de tudo que está abaixo dela. Para saber quanto uma operação gastou sozinha, desconte o que os filhos diretos gastaram. No mesmo print do nested loop, os Buffers fecham na conta: os 7.844 do NESTED LOOPS são os 1.456 do TABLE ACCESS FULL mais os 6.388 do INDEX RANGE SCAN.
Com o A-Time é parecido, mas não exato, porque o tempo é amostrado. No print, o NESTED LOOPS marca 0,03 s e a linha 0 marca 0,02 s. Use o A-Time para achar a região cara do plano, não para fazer conta de centésimo.
ALLSTATS e ALLSTATS LAST não são a mesma coisa
No DBMS_XPLAN, sem o LAST, as estatísticas somam todas as execuções do cursor; com LAST, só a última. Para ver a diferença, rode a mesma query três vezes com uma tag nova. Na sessão SH:
SET SERVEROUTPUT OFF
SET LINESIZE 250
SET PAGESIZE 0
DEFINE sql_id = fapdbwuhynakg
DEFINE child = 1
SELECT /*+ GATHER_PLAN_STATISTICS */ /* LAB_XPLAN_ALL */ cust_id, cust_last_name FROM sh.customers WHERE cust_state_province = 'CA' AND country_id = 52790;
SELECT /*+ GATHER_PLAN_STATISTICS */ /* LAB_XPLAN_ALL */ cust_id, cust_last_name FROM sh.customers WHERE cust_state_province = 'CA' AND country_id = 52790;
SELECT /*+ GATHER_PLAN_STATISTICS */ /* LAB_XPLAN_ALL */ cust_id, cust_last_name FROM sh.customers WHERE cust_state_province = 'CA' AND country_id = 52790;
SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR('&sql_id', &child, 'ALLSTATS'));
SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR('&sql_id', &child, 'ALLSTATS LAST'));
UNDEFINE sql_id
UNDEFINE childO SQL_ID vai fixo porque ele vem do texto: a mesma query gera o mesmo SQL_ID em qualquer banco. Aqui entrou o statistics feedback: depois do erro de estimativa da 1ª execução, o Oracle reotimizou o SQL e criou um cursor filho novo. A 1ª execução ficou no child 0 e a 2ª e a 3ª caíram no child 1. Por isso o bloco consulta o child 1, que é onde existe mais de uma execução para comparar. Se no seu banco só existir o child 0, troque para DEFINE child = 0: ele vai ter as 3 execuções, e a diferença fica ainda maior.
Com ALLSTATS, o child 1 aparece com Starts 2, A-Rows 6.682 e Buffers 3.350: a soma das duas execuções. Com ALLSTATS LAST, sobra só a última: Starts 1, A-Rows 3.341 e Buffers 1.675.
O E-Rows não muda entre as duas saídas, porque é a estimativa para uma execução e nunca soma. É por isso que comparar E-Rows com A-Rows no ALLSTATS sem o LAST engana: parece que o otimizador errou pela metade (3.341 contra 6.682), quando na verdade acertou. Para diagnóstico, use ALLSTATS LAST.
Direto na fonte: V$SQL_PLAN_STATISTICS_ALL
O DISPLAY_CURSOR só formata o que está na V$SQL_PLAN_STATISTICS_ALL. Se quiser os números crus (para um script, por exemplo), consulte a view. Aqui uso o child 0 da mesma query, que é a primeira execução. Na sessão SH:
SET LINESIZE 250
SET PAGESIZE 100
SET COLSEP '|'
COLUMN id FORMAT 999 HEADING 'ID|-'
COLUMN operacao FORMAT A30 HEADING 'OPERACAO|-'
COLUMN object_name FORMAT A20 HEADING 'OBJETO|-'
COLUMN cardinality FORMAT 999G999G999 HEADING 'E-ROWS|-'
COLUMN last_starts FORMAT 999G999G999 HEADING 'STARTS|-'
COLUMN last_output_rows FORMAT 999G999G999 HEADING 'A-ROWS|-'
COLUMN last_cr_buffer_gets FORMAT 999G999G999 HEADING 'CR|BUFFERS'
COLUMN last_disk_reads FORMAT 999G999G999 HEADING 'DISK|READS'
COLUMN last_elapsed_ms FORMAT 999G999D99 HEADING 'A-TIME|(ms)'
SELECT id,
LPAD(' ', depth) || operation || ' ' || options operacao,
object_name,
cardinality,
last_starts,
last_output_rows,
last_cr_buffer_gets,
last_disk_reads,
last_elapsed_time / 1000 last_elapsed_ms
FROM v$sql_plan_statistics_all
WHERE sql_id = 'fapdbwuhynakg'
AND child_number = 0
ORDER BY id;As colunas LAST_ são da última execução, LAST_ELAPSED_TIME vem em microssegundos (por isso a divisão por 1000) e CARDINALITY é a estimativa. No child 0 aparecem 1.453 leituras físicas: na primeira execução os blocos ainda não estavam no buffer cache. Nas seguintes eles já estavam em memória, e o Reads some dos planos.
E quando o SQL é da aplicação?
Em produção, a query problemática quase nunca é sua: vem de aplicação, de pacote, de ferramenta de terceiros. Não dá para colocar hint, nem ligar STATISTICS_LEVEL=ALL na sessão dela. Para esse caso existe o SQL Patch, que injeta o GATHER_PLAN_STATISTICS no SQL_ID pelo lado do banco. Mostro o passo a passo completo, com os scripts coe_sql_patch e a pegadinha do multitenant, num post próprio sobre SQL Patch com GATHER_PLAN_STATISTICS, que ainda será publicado.
Referências
Documentação oficial:
- DBMS_XPLAN, Oracle Database 19c: formatos IOSTATS, MEMSTATS, ALLSTATS e LAST.
- Explaining and Displaying Execution Plans, SQL Tuning Guide 19c: diferença entre EXPLAIN PLAN e plano executado.
- PLAN_TABLE, Database Reference 19c: colunas estimadas CARDINALITY, BYTES, COST e TIME.
- STATISTICS_LEVEL, Database Reference 19c: valores, default e o que o nível ALL coleta.
- ALTER SYSTEM, SQL Language Reference 19c: defaults de SCOPE e SID.
- V$SQL_PLAN_STATISTICS_ALL, Database Reference 19c: colunas LAST_ e unidades.
- Managing Extended Statistics, SQL Tuning Guide 19c: o exemplo CA/52790.
Da comunidade:
- Connor McDonald: Common GATHER_PLAN_STATISTICS confusion
- TuningSQL: How to get row source statistics in Oracle
- Kerry Osborne: GATHER_PLAN_STATISTICS
- FatDBA: Use GATHER_PLAN_STATISTICS hint
- Hemant K Chitale: SQL execution statistics using STATISTICS_LEVEL
Conclusão
Plano sem A-Rows e Buffers mostra, no máximo, o caminho. Os números dele são projeção, e ninguém acha gargalo em projeção. EXPLAIN PLAN responde “o que o otimizador pretende fazer”; o plano de execução real, com ALLSTATS LAST, responde “o que aconteceu e onde foi o tempo”. Para tuning, só a segunda serve de prova.
Hint no lab, STATISTICS_LEVEL=ALL na sua sessão, SQL Patch quando o SQL é da aplicação, e ALTER SYSTEM só como último recurso, em memória e com hora para desligar. Seja qual for o caminho, a regra é a mesma: coleta, analisa e desliga.
