Arquivo da tag: tunning

Oracle – SQL TRACE – TKPROF

Fala PessoAll,

Estamos aqui novamente para compartilhar mais uma experiência.

Dessa vez com algo bastante básico para quem quer se especializar em performance de aplicações, que é o meu caso!!

Em alguns momentos na nossa vida de DBA nos deparamos com processos que são um tanto quanto complexos de serem analisados, por exemplo: Uma procedure que demora muito ou uma query que demora demais para retornar ou um procedimento inteiro que tem todas as querys otimizadas mas demora muito entre outras coisas. Para que possamos analisar estes tipos de problemas, temos um grande aliado que é o SQL_TRACE, ele vai gerar uma espécie de “relatório” com todas as query´s envolvidas no processamento, e nos mostrar o que cada query fez, o plano de execução de cada uma, quanto tempo demorou para rodar, quanto de CPU consumiu, quantas vezes foi executada, isso nos dá uma visão exata do que está ocorrendo, podendo ser até um erro de lógica na aplicação, onde por exemplo, devido a um erro uma determinada query é executada milhares de vezes sem necessidade.

Hoje vou mostrar como fazemos para gerar um trace de uma determinada operação no banco e como formatar este trace de forma que possamos ler e entender o passo a passo da execução. Vamos lá!

O primeiro passo é alterar a sessão que o processo vai rodar para que o trace seja gerado, isso pode ser feito com o comando:

ALTER SESSION SET SQL_TRACE=TRUE;

Após este commando, podemos executar a nossa rotina lenta, que um arquivo será gerado com o que esta rotina fez.

Begin
Nossa_Rotina_Lenta(1,4,4);
End;

Após a conclusão do processamento, devemos ir até o local onde foi gerado o arquivo, no meu caso, o arquivo é gerado no caminho: {ORACLE_BASE}adminnegraodudump

Se você tentar abrir o arquivo gerado, possivelmente não vai conseguir entender nada! Para que nosso arquivo fique legível, vamos usar um utilitário chamado TKPROF. Esse utilitário tem como objetivo interpretar o trace e deixar ele num formato legível.

O uso do TKPROF é da seguinte forma: tkprof trace.trc arquivo_saida.txt explain=usuário/senha@banco

Depois deste comando executado, no seu arquivo de saída, terá um conteúdo parecido com este:

********************************************************************************
count = Numero de vezes que o procedimento foi executado
cpu = Tempo em segundos executando pelo CPU
elapsed = Tem em segundos para execução do procedimento
disk = Numero de leituras físicas no disco
rows = Numero de linhas processadas pelo comando
********************************************************************************

SELECT COUNT(*)
FROM dual

call count cpu elapsed disk query current rows
——- —– —– ——- ——- ——- ——- ——-
Parse 1 0.02 0.02 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 1 4 1
——- —– —– ——- ——- ——- ——- ——-
total 4 0.02 0.02 0 1 4 1

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 121

Rows Row Source Operation
——- —————————————————
1 SORT AGGREGATE
1 TABLE ACCESS FULL DUAL

Neste exemplo, conseguimos ler e ver o que aconteceu com a query, além do plano de execução que ela utilizou para executar.

Depois disso é analisar as query´s mais complexas e atacar na mudança delas, em muitos casos é necessário a mudança da lógica da rotina, para que se possa ganhar alguma performance!

É isso pessoal. Espero que ajude vocês!

Atc.
Gerson Júnior
gerson.vasconcelos@gmail.com