exemplo-10046.trc
Sessão e ambiente
- Banco
- Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production · 19.3.0.0.0
- Instância
- ORCL1
- Servidor
- db-exemplo
- Sessão
- 10.20 · pid 4242
- Módulo
- app-exemplo
- Unidade de tempo
- microssegundos
- Arquivo no servidor
- /u01/app/oracle/diag/rdbms/orcl/ORCL1/trace/ORCL1_ora_4242.trc
Diagnóstico
Padrões que costumam explicar o que o trace mostra, em ordem de severidade. São pistas para a análise, não conclusões.
O banco ficou ocioso esperando o próximo pedido do cliente. Ajuste de SQL não reduz esse tempo: olhe a aplicação, a rede e a quantidade de idas e voltas (chamadas por unidade de trabalho). Ver no perfil
Operação TABLE ACCESS BY INDEX ROWID T. Visita a tabela linha a linha a partir do índice: índice pouco seletivo ou sem as colunas que o filtro usa. Também pesam: operação 2, INDEX UNIQUE SCAN T_PK (20,0% das leituras lógicas). As operações estão destacadas no plano, no detalhe do comando. Ver no plano do comando #1
Perfil do tempo de resposta
Cada linha é uma parte do tempo total; somadas, dão 100%. Clique no nome de um componente ou de uma classe para ver o que esse tempo significa, quando ele é normal, quando indica problema e onde conferir no relatório. Tempo não contabilizado é o que o trace não explica por CPU nem por espera: dentro das chamadas, costuma ser fila de CPU ou código sem instrumentação; o valor negativo vem da granularidade da medida de CPU.
| Componente | Duração (s) | % do total | gráfico | Ocorrências | Média (s) | Mín (s) | Máx (s) |
|---|---|---|---|---|---|---|---|
| Idle | 0,005000 | 71,3 | 1 | 0,005000 | 0,005000 | 0,005000 | |
| User I/O | 0,001300 | 18,5 | 2 | 0,000650 | 0,000300 | 0,001000 | |
| não contabilizado | 0,000286 | 4,1 | |||||
| cpu | 0,000195 | 2,8 | 2 | 0,000097 | 0,000040 | 0,000155 | |
| não contabilizado | 0,000161 | 2,3 | 6 | 0,000027 | |||
| cpu | 0,000050 | 0,7 | 1 | 0,000050 | 0,000050 | 0,000050 | |
| cpu | 0,000015 | 0,2 | 2 | 0,000008 | 0,000005 | 0,000010 | |
| Network | 0,000002 | 0,0 | 1 | 0,000002 | 0,000002 | 0,000002 | |
| cpu | 0,000001 | 0,0 | 1 | 0,000001 | 0,000001 | 0,000001 | |
| Total | 0,007010 | 100,0 | |||||
Por classe de espera
Os mesmos componentes agrupados pela classe de espera do Oracle (wait_class), com CPU e tempo não contabilizado à parte. A soma também é o tempo total.
| Classe | Duração (s) | % do total | gráfico | Ocorrências | Principais componentes |
|---|---|---|---|---|---|
| 0,005000 | 71,3 | 1 | SQL*Net message from client | ||
| 0,001300 | 18,5 | 2 | db file sequential read | ||
| 0,000447 | 6,4 | tempo não contabilizado entre chamadas · tempo não contabilizado dentro das chamadas | |||
| 0,000261 | 3,7 | 6 | CPU: FETCH dbcalls · CPU: PARSE dbcalls · CPU: EXEC dbcalls · CPU: CLOSE dbcalls | ||
| 0,000002 | 0,0 | 1 | SQL*Net message to client |
Principais comandos por componente e por classe
Quanto cada comando gastou em cada componente do perfil e em cada classe de espera, pelo perfil exclusivo do comando (sem o SQL recursivo que ele dispara). Até 10 comandos por lista: mude no topo da página.
Por componente do perfil
SQL*Net message from client espera0,005 s · 71,3% do tempo total · 1 comando
| # | Tempo (s) | % do total | gráfico | SQL ID | Texto |
|---|---|---|---|---|---|
| 1 | 0,005000 | 100,0 | 7zq3k1c9m2x4p | select * from t where id=*** |
db file sequential read espera0,001 s · 18,5% do tempo total · 2 comandos
| # | Tempo (s) | % do total | gráfico | SQL ID | Texto |
|---|---|---|---|---|---|
| 1 | 0,001000 | 76,9 | 7zq3k1c9m2x4p | select * from t where id=*** | |
| 2 | 0,000300 | 23,1 | 0w5n8r2t6v1yb | select obj# from obj$ where x=*** |
CPU: FETCH dbcalls cpu0,000 s · 2,8% do tempo total · 2 comandos
| # | Tempo (s) | % do total | gráfico | SQL ID | Texto |
|---|---|---|---|---|---|
| 1 | 0,000155 | 79,5 | 7zq3k1c9m2x4p | select * from t where id=*** | |
| 2 | 0,000040 | 20,5 | 0w5n8r2t6v1yb | select obj# from obj$ where x=*** |
tempo não contabilizado dentro das chamadas não contabilizado0,000 s · 2,3% do tempo total · 2 comandos
| # | Tempo (s) | % do total | gráfico | SQL ID | Texto |
|---|---|---|---|---|---|
| 1 | 0,000116 | 72,0 | 7zq3k1c9m2x4p | select * from t where id=*** | |
| 2 | 0,000045 | 28,0 | 0w5n8r2t6v1yb | select obj# from obj$ where x=*** |
CPU: PARSE dbcalls cpu0,000 s · 0,7% do tempo total · 1 comando
| # | Tempo (s) | % do total | gráfico | SQL ID | Texto |
|---|---|---|---|---|---|
| 1 | 0,000050 | 100,0 | 7zq3k1c9m2x4p | select * from t where id=*** |
CPU: EXEC dbcalls cpu0,000 s · 0,2% do tempo total · 2 comandos
| # | Tempo (s) | % do total | gráfico | SQL ID | Texto |
|---|---|---|---|---|---|
| 1 | 0,000010 | 66,7 | 7zq3k1c9m2x4p | select * from t where id=*** | |
| 2 | 0,000005 | 33,3 | 0w5n8r2t6v1yb | select obj# from obj$ where x=*** |
SQL*Net message to client espera0,000 s · 0,0% do tempo total · 1 comando
| # | Tempo (s) | % do total | gráfico | SQL ID | Texto |
|---|---|---|---|---|---|
| 1 | 0,000002 | 100,0 | 7zq3k1c9m2x4p | select * from t where id=*** |
CPU: CLOSE dbcalls cpu0,000 s · 0,0% do tempo total · 1 comando
| # | Tempo (s) | % do total | gráfico | SQL ID | Texto |
|---|---|---|---|---|---|
| 1 | 0,000001 | 100,0 | 7zq3k1c9m2x4p | select * from t where id=*** |
Por classe de espera
Idle0,005 s · 71,3% do tempo total · 1 comando
| # | Tempo (s) | % do total | gráfico | SQL ID | Texto |
|---|---|---|---|---|---|
| 1 | 0,005000 | 100,0 | 7zq3k1c9m2x4p | select * from t where id=*** |
User I/O0,001 s · 18,5% do tempo total · 2 comandos
| # | Tempo (s) | % do total | gráfico | SQL ID | Texto |
|---|---|---|---|---|---|
| 1 | 0,001000 | 76,9 | 7zq3k1c9m2x4p | select * from t where id=*** | |
| 2 | 0,000300 | 23,1 | 0w5n8r2t6v1yb | select obj# from obj$ where x=*** |
Não contabilizado0,000 s · 6,4% do tempo total · 2 comandos
| # | Tempo (s) | % do total | gráfico | SQL ID | Texto |
|---|---|---|---|---|---|
| 1 | 0,000116 | 26,0 | 7zq3k1c9m2x4p | select * from t where id=*** | |
| 2 | 0,000045 | 10,1 | 0w5n8r2t6v1yb | select obj# from obj$ where x=*** |
CPU0,000 s · 3,7% do tempo total · 2 comandos
| # | Tempo (s) | % do total | gráfico | SQL ID | Texto |
|---|---|---|---|---|---|
| 1 | 0,000216 | 82,8 | 7zq3k1c9m2x4p | select * from t where id=*** | |
| 2 | 0,000045 | 17,2 | 0w5n8r2t6v1yb | select obj# from obj$ where x=*** |
Network0,000 s · 0,0% do tempo total · 1 comando
| # | Tempo (s) | % do total | gráfico | SQL ID | Texto |
|---|---|---|---|---|---|
| 1 | 0,000002 | 100,0 | 7zq3k1c9m2x4p | select * from t where id=*** |
Comandos SQL por contribuição
Contribuição: duração das chamadas de nível 0 do comando somada às esperas entre chamadas no cursor dele. Inclusivo: soma de todas as chamadas do comando, em qualquer profundidade.
| # | Contribuição (s) | % do total | Inclusivo (s) | Tipo | Prof. | Exec | Fetch | Linhas | LIO | PIO | SQL ID | Texto |
|---|---|---|---|---|---|---|---|---|---|---|---|---|
| 1 | 0,007 | 95,9 | 0,002 | SELECT | 0 | 1 | 1 | 1 | 10 | 1 | 7zq3k1c9m2x4p | select * from t where id=*** |
| 2 | 0,000 | 0,0 | 0,000 | SELECT | 1 | 1 | 1 | 1 | 3 | 1 | 0w5n8r2t6v1yb | select obj# from obj$ where x=*** |
Tempo não atribuído a nenhum comando: 0,000 s.
Tipos de chamada
| Chamada | Quantidade | CPU (s) | Duração (s) | Disco (PIO) | Consistente (CR) | Corrente (CU) | Linhas | Misses |
|---|---|---|---|---|---|---|---|---|
| FETCH | 2 | 0,000 | 0,002 | 2 | 13 | 0 | 2 | 0 |
| PARSE | 1 | 0,000 | 0,000 | 0 | 0 | 0 | 0 | 1 |
| EXEC | 2 | 0,000 | 0,000 | 0 | 0 | 0 | 0 | 0 |
| CLOSE | 1 | 0,000 | 0,000 | 0 | 0 | 0 | 0 | 0 |
Chamadas de nível 0 mais longas
| Chamada | Duração (s) | CPU (s) | Início (+s) | Linha | LIO | PIO | Linhas | Comando |
|---|---|---|---|---|---|---|---|---|
| FETCH | 0,001600 | 0,000200 | 0,000 | 31 | 10 | 1 | 1 | #1 select * from t where id=*** |
| PARSE | 0,000100 | 0,000050 | 0,000 | 17 | 0 | 0 | 0 | #1 select * from t where id=*** |
| EXEC | 0,000020 | 0,000010 | 0,000 | 18 | 0 | 0 | 0 | #1 select * from t where id=*** |
| CLOSE | 0,000002 | 0,000001 | 0,007 | 35 | 0 | 0 | 0 | #1 select * from t where id=*** |
Distribuição de latência
Faixas em potências de 10, por evento de espera e por tipo de chamada. Mostra se o tempo vem de muitas ocorrências rápidas ou de poucas lentas.
SQL*Net message from client1 ocorrências · 0,005 s
| Faixa da duração | Ocorrências | % ocorr. | Duração (s) | % duração | |
|---|---|---|---|---|---|
| 0 ≤ e < 1 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 µs ≤ e < 10 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 µs ≤ e < 100 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 µs ≤ e < 1 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 ms ≤ e < 10 ms | 1 | 100,0 | 0,005000 | 100,0 | |
| 10 ms ≤ e < 100 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 ms ≤ e < 1 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 s ≤ e < 10 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 s ≤ e < 100 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 s ≤ e < 1.000 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 1.000 s ≤ e < ∞ | 0 | 0,0 | 0,000000 | 0,0 |
db file sequential read2 ocorrências · 0,001 s
| Faixa da duração | Ocorrências | % ocorr. | Duração (s) | % duração | |
|---|---|---|---|---|---|
| 0 ≤ e < 1 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 µs ≤ e < 10 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 µs ≤ e < 100 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 µs ≤ e < 1 ms | 1 | 50,0 | 0,000300 | 23,1 | |
| 1 ms ≤ e < 10 ms | 1 | 50,0 | 0,001000 | 76,9 | |
| 10 ms ≤ e < 100 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 ms ≤ e < 1 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 s ≤ e < 10 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 s ≤ e < 100 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 s ≤ e < 1.000 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 1.000 s ≤ e < ∞ | 0 | 0,0 | 0,000000 | 0,0 |
SQL*Net message to client1 ocorrências · 0,000 s
| Faixa da duração | Ocorrências | % ocorr. | Duração (s) | % duração | |
|---|---|---|---|---|---|
| 0 ≤ e < 1 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 µs ≤ e < 10 µs | 1 | 100,0 | 0,000002 | 100,0 | |
| 10 µs ≤ e < 100 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 µs ≤ e < 1 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 ms ≤ e < 10 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 ms ≤ e < 100 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 ms ≤ e < 1 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 s ≤ e < 10 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 s ≤ e < 100 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 s ≤ e < 1.000 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 1.000 s ≤ e < ∞ | 0 | 0,0 | 0,000000 | 0,0 |
FETCH (duração e da chamada)2 ocorrências · 0,002 s
| Faixa da duração | Ocorrências | % ocorr. | Duração (s) | % duração | |
|---|---|---|---|---|---|
| 0 ≤ e < 1 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 µs ≤ e < 10 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 µs ≤ e < 100 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 µs ≤ e < 1 ms | 1 | 50,0 | 0,000380 | 19,2 | |
| 1 ms ≤ e < 10 ms | 1 | 50,0 | 0,001600 | 80,8 | |
| 10 ms ≤ e < 100 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 ms ≤ e < 1 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 s ≤ e < 10 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 s ≤ e < 100 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 s ≤ e < 1.000 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 1.000 s ≤ e < ∞ | 0 | 0,0 | 0,000000 | 0,0 |
PARSE (duração e da chamada)1 ocorrências · 0,000 s
| Faixa da duração | Ocorrências | % ocorr. | Duração (s) | % duração | |
|---|---|---|---|---|---|
| 0 ≤ e < 1 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 µs ≤ e < 10 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 µs ≤ e < 100 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 µs ≤ e < 1 ms | 1 | 100,0 | 0,000100 | 100,0 | |
| 1 ms ≤ e < 10 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 ms ≤ e < 100 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 ms ≤ e < 1 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 s ≤ e < 10 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 s ≤ e < 100 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 s ≤ e < 1.000 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 1.000 s ≤ e < ∞ | 0 | 0,0 | 0,000000 | 0,0 |
EXEC (duração e da chamada)2 ocorrências · 0,000 s
| Faixa da duração | Ocorrências | % ocorr. | Duração (s) | % duração | |
|---|---|---|---|---|---|
| 0 ≤ e < 1 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 µs ≤ e < 10 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 µs ≤ e < 100 µs | 2 | 100,0 | 0,000030 | 100,0 | |
| 100 µs ≤ e < 1 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 ms ≤ e < 10 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 ms ≤ e < 100 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 ms ≤ e < 1 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 s ≤ e < 10 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 s ≤ e < 100 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 s ≤ e < 1.000 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 1.000 s ≤ e < ∞ | 0 | 0,0 | 0,000000 | 0,0 |
CLOSE (duração e da chamada)1 ocorrências · 0,000 s
| Faixa da duração | Ocorrências | % ocorr. | Duração (s) | % duração | |
|---|---|---|---|---|---|
| 0 ≤ e < 1 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 µs ≤ e < 10 µs | 1 | 100,0 | 0,000002 | 100,0 | |
| 10 µs ≤ e < 100 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 µs ≤ e < 1 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 ms ≤ e < 10 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 ms ≤ e < 100 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 ms ≤ e < 1 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 s ≤ e < 10 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 s ≤ e < 100 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 s ≤ e < 1.000 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 1.000 s ≤ e < ∞ | 0 | 0,0 | 0,000000 | 0,0 |
Leituras
leituras (faixas de disco)2 ocorrências · 0,001 s
| Faixa da duração | Ocorrências | % ocorr. | Duração (s) | % duração | |
|---|---|---|---|---|---|
| 0 ≤ e < 5 ms | 2 | 100,0 | 0,001300 | 100,0 | |
| 5 ms ≤ e < 10 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 10 ms ≤ e < 15 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 15 ms ≤ e < 20 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 20 ms ≤ e < 25 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 25 ms ≤ e < 50 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 50 ms ≤ e < 100 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 ms ≤ e < 1 s | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 s ≤ e < ∞ | 0 | 0,0 | 0,000000 | 0,0 |
leituras (faixas de SSD)2 ocorrências · 0,001 s
| Faixa da duração | Ocorrências | % ocorr. | Duração (s) | % duração | |
|---|---|---|---|---|---|
| 0 ≤ e < 15 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 15 µs ≤ e < 25 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 25 µs ≤ e < 50 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 50 µs ≤ e < 100 µs | 0 | 0,0 | 0,000000 | 0,0 | |
| 100 µs ≤ e < 500 µs | 1 | 50,0 | 0,000300 | 23,1 | |
| 500 µs ≤ e < 1 ms | 0 | 0,0 | 0,000000 | 0,0 | |
| 1 ms ≤ e < 10 ms | 1 | 50,0 | 0,001000 | 76,9 | |
| 10 ms ≤ e < ∞ | 0 | 0,0 | 0,000000 | 0,0 |
Primeira leitura e releitura do mesmo bloco
Releitura frequente do mesmo bloco indica cache pequeno ou acesso repetido ao mesmo dado.
| Evento | Blocos distintos | 1ª leitura | 1ª leitura (s) | Releituras | Releituras (s) |
|---|---|---|---|---|---|
| db file sequential read | 1 | 1 | 0,000 | 1 | 0,001 |
Objetos com mais tempo de espera
Pelo obj# das esperas. O nome vem das linhas STAT do próprio trace, quando existem.
| obj# | Nome | Espera (s) | Ocorrências | Eventos principais |
|---|---|---|---|---|
| 50 | T | 0,001 | 2 | db file sequential read |
Esperando a aplicação
SQL*Net message from client
A sessão terminou a chamada anterior e espera o próximo pedido da aplicação. É tempo da aplicação, da rede e do usuário, não do banco.
- Normal quando
- Aparece entre todas as chamadas. Esperas longas e isoladas são o usuário pensando ou a aplicação ocupada com outra coisa.
- Preocupa quando
- Domina o tempo total com muitas esperas curtas: a aplicação conversa demais com o banco (uma linha por chamada, SQL dentro de laço). Com poucas esperas longas, a demora está na aplicação, e ajuste de SQL não resolve.
- Onde olhar
- Quantas idas e voltas houve e quanto dura cada uma: Perfil, linha deste componente: colunas Ocorrências e Média (s)
- Muitas esperas curtas ou poucas longas: Distribuição de latência, tabela deste evento
- FETCH que trazem poucas linhas cada: Tipos de chamada, linha FETCH: Quantidade e Linhas
- Comandos que mais esperaram a aplicação: Principais comandos por componente, grupo deste evento
Leitura de um bloco
db file sequential read
Lê um bloco do disco para o buffer cache: acesso por índice, à tabela via ROWID, a undo ou a cabeçalho de segmento.
- Normal quando
- Acesso por índice a poucos blocos, com média de 0,1 a 1 ms em SSD ou flash e de 5 a 10 ms em disco.
- Preocupa quando
- Muitas leituras: o plano lê blocos demais (índice pouco seletivo, NESTED LOOPS com muitas linhas). Média alta: armazenamento lento ou disputado.
- Onde olhar
- Quantas leituras e quanto dura cada uma: Perfil, linha deste componente: colunas Ocorrências e Média (s)
- Leituras lentas, ou muitas leituras rápidas: Distribuição de latência, tabela deste evento
- Objetos mais lidos: Objetos com mais tempo de espera
- Releitura dos mesmos blocos: Leituras, primeira leitura e releitura do mesmo bloco
- Comandos que mais leram: Principais comandos por componente, grupo deste evento
- Operações do plano que leem blocos demais: detalhe do comando, Plano de execução: operações em destaque
Tempo não contabilizado entre chamadas
tempo não contabilizado entre chamadas
Tempo entre o fim de uma chamada de nível 0 e o início da próxima sem nenhuma espera registrada. É a diferença entre o tempo total e a soma das chamadas e das esperas entre elas.
- Normal quando
- Pequeno: frações de milissegundo por chamada.
- Preocupa quando
- Soma muito: o trace foi ligado ou desligado no meio, o processo ficou fora da CPU (servidor saturado), a aplicação demorou sem a espera de cliente aparecer, ou falta arquivo da coleta.
- Onde olhar
- Período do trace e lacunas grandes de tempo: Resumo, Período
- Em coleta, se todos os arquivos vieram: Coleta, arquivos e sessões
- Chamadas separadas por lacunas: Chamadas de nível 0 mais longas
CPU nas chamadas FETCH
CPU: FETCH dbcalls
Tempo de CPU da sessão na busca das linhas. Alto: leituras lógicas demais (LIO), em geral um plano que lê muito mais blocos do que as linhas devolvidas pedem.
- Normal quando
- É parte do trabalho normal do banco.
- Preocupa quando
- Domina o tempo total: comece pelos comandos que mais gastam CPU e pelas leituras lógicas deles.
- Onde olhar
- CPU por tipo de chamada: Tipos de chamada
- Comandos com mais leituras lógicas: Comandos SQL, colunas LIO e Linhas
- Comandos que mais gastaram CPU nesta chamada: Principais comandos por componente, grupo desta chamada
- Operações do plano com LIO próprio alto: detalhe do comando, Plano de execução: operações em destaque
Tempo não contabilizado dentro das chamadas
tempo não contabilizado dentro das chamadas
Parte da duração da chamada (e=) que não é CPU (c=) nem espera registrada dentro dela.
- Normal quando
- Pequeno. Valor negativo vem da granularidade da medida de CPU, não de problema.
- Preocupa quando
- Soma muito: fila de CPU (mais processos prontos que núcleos), paginação de memória (swap) ou código sem instrumentação de espera.
- Onde olhar
- Chamadas em que o tempo some (duração muito acima de CPU mais esperas): Chamadas de nível 0 mais longas
- Comandos que mais carregam esse tempo: Principais comandos por componente, grupo deste evento
- Carga de CPU e memória livre do servidor no período, fora do relatório
CPU nas chamadas PARSE
CPU: PARSE dbcalls
Tempo de CPU da sessão na análise do SQL (parse). Alto: hard parse por SQL sem bind, ou parse repetido do mesmo cursor (abrir e fechar a cada execução).
- Normal quando
- É parte do trabalho normal do banco.
- Preocupa quando
- Domina o tempo total: comece pelos comandos que mais gastam CPU e pelas leituras lógicas deles.
- Onde olhar
- Hard parses: Tipos de chamada, linha PARSE: Quantidade e Misses
- Comandos que só mudam os literais: Textos compartilháveis
- PARSE a cada EXEC: detalhe do comando, Chamadas: PARSE em relação a EXEC
- Comandos que mais gastaram CPU nesta chamada: Principais comandos por componente, grupo desta chamada
CPU nas chamadas EXEC
CPU: EXEC dbcalls
Tempo de CPU da sessão na execução: DML, abertura do cursor e corpo de blocos PL/SQL. Alto em PL/SQL: lógica pesada ou SQL dentro de laço.
- Normal quando
- É parte do trabalho normal do banco.
- Preocupa quando
- Domina o tempo total: comece pelos comandos que mais gastam CPU e pelas leituras lógicas deles.
- Onde olhar
- CPU por tipo de chamada: Tipos de chamada
- Comandos com mais leituras lógicas: Comandos SQL, colunas LIO e Linhas
- Comandos que mais gastaram CPU nesta chamada: Principais comandos por componente, grupo desta chamada
- Comandos filhos dos blocos PL/SQL: detalhe do comando, SQL recursivo
Mandando a resposta
SQL*Net message to client
Tempo para entregar um pacote de resposta ao sistema operacional. Não mede a rede até o cliente, só a entrega ao SO.
- Normal quando
- Microssegundos por ocorrência, uma por chamada.
- Preocupa quando
- A média sobe para milissegundos: buffer de rede do servidor cheio ou rede saturada.
- Onde olhar
- Média e máximo por espera: Perfil, linha deste componente: colunas Média (s) e Máx (s)
CPU nas chamadas CLOSE
CPU: CLOSE dbcalls
Tempo de CPU da sessão no fechamento do cursor. Quase sempre pequeno.
- Normal quando
- É parte do trabalho normal do banco.
- Preocupa quando
- Domina o tempo total: comece pelos comandos que mais gastam CPU e pelas leituras lógicas deles.
- Onde olhar
- CPU por tipo de chamada: Tipos de chamada
- Comandos com mais leituras lógicas: Comandos SQL, colunas LIO e Linhas
- Comandos que mais gastaram CPU nesta chamada: Principais comandos por componente, grupo desta chamada
- Comandos filhos dos blocos PL/SQL: detalhe do comando, SQL recursivo
Idle (ociosa)
Idle
A sessão espera trabalho. Num trace de sessão, quase sempre é SQL*Net message from client: tempo da aplicação, da rede e do usuário.
- Normal quando
- Aparece entre as chamadas.
- Preocupa quando
- Domina o tempo total e o usuário reclama da demora: a lentidão está fora do banco (aplicação, rede, idas e voltas demais).
- Onde olhar
- Quantas idas e voltas houve: Resumo, Chamadas ao banco e Esperas
- FETCH que trazem poucas linhas cada: Tipos de chamada, linha FETCH: Quantidade e Linhas
- Comandos que mais esperaram a aplicação: Principais comandos por classe, grupo desta classe
User I/O (leitura e escrita de dados)
User I/O
Leituras e gravações de dados feitas pela própria sessão.
- Normal quando
- Algum I/O sempre há, com média baixa por leitura.
- Preocupa quando
- Blocos demais (o plano lê mais do que precisa) ou tempo médio alto por leitura (armazenamento lento).
- Onde olhar
- Quais eventos de I/O pesam: Por classe de espera, linha desta classe: coluna Principais componentes
- Leituras lentas, ou muitas leituras rápidas: Distribuição de latência
- Objetos mais lidos: Objetos com mais tempo de espera
- Comandos que mais leram: Principais comandos por classe, grupo desta classe
- Operações do plano que leem blocos demais: detalhe do comando, Plano de execução: operações em destaque
Não contabilizado
Não contabilizado
Tempo que o trace não explica por CPU nem por espera: dentro das chamadas e entre elas.
- Normal quando
- Pequeno.
- Preocupa quando
- Fila de CPU, paginação, lacunas no trace ou arquivo faltando na coleta.
- Onde olhar
- Os dois componentes de tempo não contabilizado e o cartão de cada um: Perfil do tempo de resposta
CPU
CPU
Tempo de CPU das chamadas ao banco (o c= de PARSE, EXEC e FETCH).
- Normal quando
- É o trabalho do banco.
- Preocupa quando
- Soma muito: leituras lógicas demais (plano), parse em excesso ou PL/SQL pesado.
- Onde olhar
- CPU por tipo de chamada: Tipos de chamada
- Comandos com mais leituras lógicas: Comandos SQL, colunas LIO e Linhas
- Comandos que mais gastaram CPU: Principais comandos por classe, grupo desta classe
Network (rede)
Network
Mandar e receber dados pelo SQL*Net, com a aplicação ou com outro banco por dblink.
- Normal quando
- Soma pouco tempo.
- Preocupa quando
- Resultados grandes, arraysize baixo ou dblink lento.
- Onde olhar
- Quais eventos da classe pesam (more data, dblink): Por classe de espera, linha desta classe: coluna Principais componentes
- Linhas por FETCH: Tipos de chamada, linha FETCH: Quantidade e Linhas
- Comandos que mais usaram a rede: Principais comandos por classe, grupo desta classe
SQL recursivo (comandos filhos)
SQL recursivo (comandos filhos)
Tempo das chamadas que este comando disparou: SQL dentro de funções e procedures PL/SQL, triggers e consultas ao dicionário.
- Normal quando
- Comando PL/SQL que executa outros SQL.
- Preocupa quando
- Soma muito num SELECT ou DML simples: função PL/SQL chamada por linha, ou trigger pesado.
- Onde olhar
- Quais comandos filhos e quanto custa cada um: detalhe do comando, SQL recursivo
#1 · SELECT
sql_id 7zq3k1c9m2x4phv 111Texto
select * from t12 where id=***
- 1 T: operação 1 do plano
- 2 T, tabela do índice T_PK: operação 2 do plano
Perfil do comando
| Componente | Duração (s) | % | Ocorrências | |
|---|---|---|---|---|
| espera | 0,005000 | 74,4 | 1 | |
| espera | 0,001000 | 14,9 | 1 | |
| recursivo | 0,000390 | 5,8 | ||
| cpu | 0,000155 | 2,3 | 1 | |
| não contabilizado | 0,000116 | 1,7 | 4 | |
| cpu | 0,000050 | 0,7 | 1 | |
| cpu | 0,000010 | 0,1 | 1 | |
| espera | 0,000002 | 0,0 | 1 | |
| cpu | 0,000001 | 0,0 | 1 |
Chamadas
| Chamada | Quantidade | CPU (s) | Duração (s) | Disco (PIO) | Consistente (CR) | Corrente (CU) | Linhas | Misses |
|---|---|---|---|---|---|---|---|---|
| PARSE | 1 | 0,000050 | 0,000100 | 0 | 0 | 0 | 0 | 1 |
| EXEC | 1 | 0,000010 | 0,000020 | 0 | 0 | 0 | 0 | 0 |
| FETCH | 1 | 0,000200 | 0,001600 | 1 | 10 | 0 | 1 | 0 |
| CLOSE | 1 | 0,000001 | 0,000002 | 0 | 0 | 0 | 0 | 0 |
Plano de execução 10
Das linhas STAT do trace.
Onde o plano gasta pelo valor próprio de cada operação, sem o das operações abaixo dela
- 1 Id 1 · TABLE ACCESS BY INDEX ROWID T 98,0% do tempo · 80,0% das leituras lógicas
Visita a tabela linha a linha a partir do índice: índice pouco seletivo ou sem as colunas que o filtro usa. - 2 Id 2 · INDEX UNIQUE SCAN T_PK 2,0% do tempo · 20,0% das leituras lógicas
| Id | Operação | Exec. | Linhas | Linhas/exec | Estimado | Tempo próprio (s) | % tempo | LIO próprio | % LIO | PR | PW | Tempo (s) | CR | Custo | obj |
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| 1 | 1 | 1 | 1 | 0,001470 | 98,0 | 8 | 80,0 | 1 | 0 | 0,001500 | 10 | 2 | 50 | ||
| 2 | 2 | 1 | 1 | 0,000030 | 2,0 | 2 | 20,0 | 0 | 0 | 0,000030 | 2 | 1 | 51 |
Acesso à tabela pelo ROWID do índice
TABLE ACCESS BY INDEX ROWID
Acessa a tabela, uma linha por vez, pelos ROWIDs que o index scan logo abaixo devolveu.
- Boa quando
- Poucas linhas, ou linhas guardadas perto umas das outras na tabela (clustering factor baixo).
- Ruim quando
- Muitas linhas espalhadas (clustering factor alto): quase um bloco lido por linha. Ou um filter predicate aplicado só aqui, que descarta a maior parte do que o índice trouxe: falta no índice a coluna desse predicado.
- No plano, olhe
- Linhas desta operação comparadas com as do index scan logo abaixo: se aqui sobram bem menos, o filtro está na tabela e não no índice.
Busca por chave única
INDEX UNIQUE SCAN
Busca uma única chave num índice único (PK ou UNIQUE): desce do root block pelos branch blocks até o leaf block da chave.
- Boa quando
- Quase sempre: lê só a altura do índice (BLEVEL + 1 blocos).
- Ruim quando
- Como inner de um NESTED LOOPS com milhões de linhas no outer: barato por execução, caro no total.
- No plano, olhe
- Exec: milhares de execuções pesam mesmo com LIO próprio baixo em cada uma.
Clique numa operação para ver o que ela faz, quando é boa, quando é ruim e que colunas do plano conferir. Tempo (s) e CR são acumulados: incluem as operações abaixo de cada uma (os row sources de entrada); os valores próprios descontam essas operações. O Oracle mede o tempo por operação por amostragem, então ele pode não fechar entre uma operação e as de baixo; as leituras lógicas são contadas sempre. Linhas/exec e Estimado em vermelho: o otimizador errou a cardinalidade por 10 vezes ou mais.
SQL recursivo executado por este comando
| # | Duração (s) | Texto |
|---|---|---|
| 2 | 0,000 | select obj# from obj$ where x=*** |
#2 · SELECT
sql_id 0w5n8r2t6v1ybhv 222Texto
select obj# from obj$ where x=***
Perfil do comando
| Componente | Duração (s) | % | Ocorrências | |
|---|---|---|---|---|
| espera | 0,000300 | 76,9 | 1 | |
| não contabilizado | 0,000045 | 11,5 | 2 | |
| cpu | 0,000040 | 10,3 | 1 | |
| cpu | 0,000005 | 1,3 | 1 |
Chamadas
| Chamada | Quantidade | CPU (s) | Duração (s) | Disco (PIO) | Consistente (CR) | Corrente (CU) | Linhas | Misses |
|---|---|---|---|---|---|---|---|---|
| EXEC | 1 | 0,000005 | 0,000010 | 0 | 0 | 0 | 0 | 0 |
| FETCH | 1 | 0,000040 | 0,000380 | 1 | 3 | 0 | 1 | 0 |
Objeto 50 · T
tabela- Espera (s)
- 0,001
- Ocorrências
- 2
- Eventos principais
- db file sequential read
Onde aparece no trace
- Comando #1, operação 1 TABLE ACCESS BY INDEX ROWID T
As consultas prontas para rodar no banco ficam na página do objeto, na console.
Objeto 51 · T_PK
índiceOnde aparece no trace
- Comando #1, operação 2 INDEX UNIQUE SCAN T_PK
As consultas prontas para rodar no banco ficam na página do objeto, na console.
WaitScope 1.7.0 · análise feita no servidor · relatório exportado em 29/10/2026 10:19:56