Começando a entender o que nos diz o arquivo de trace.
Bom dia a todos! E o tempo passa… Já perceberam? Estamos em março, o primeiro trimestre do ano está pra acabar. Está na hora de focar mais ainda na sua meta, deixar apenas de planejar e por em prática os planos para 2016 antes que eles virem planos para 2017, 18, 19…. rsrsrs. Pense nisso!
Ok, hora de parar de filosofar e vamos ao trabalho que está virando o mês e a usuária com certeza virá nos cobrar o seu relatório que está lento ainda.
Vamos lá? Estávamos tentando ajudar uma usuária a Sra Elisângela lembra? É! Aquela do relatório. Se o caso fosse real ela já teria nos trucidado pela demora não é mesmo? Hehehe.
Relembrando então tínhamos feito um trace da sessão dela, geramos o arquivo com o TKPROF e agora precisaríamos analisar ele.
Abaixo segue um exemplo do início de um arquivo de trace após ter sido utilizado o TKPROF
TKPROF: Release 11.2.0.3.0 – Development on Mon Feb 2 16:58:17 2014
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
Trace file: ORCL_ora_10144.trc Nome do arquivo do trace gerado no sistema que deu origem ao txt que estamos lendo
Sort options: fchela Formato de ordenação que as instruções SQL vão aparecer dentro do trace. fchela mostra primeiro a query com maior tempo de execução. Normalmente é o que eu uso para detectar problemas deste nível.
********************************************************************************
count = number of times OCI procedure was executed Número de vezes que executou a query
cpu = cpu time in seconds executing tempo de CPU na execução
elapsed = elapsed time in seconds executing tempo total gasto para executar
disk = number of physical reads of buffers from disk número de leituras físicas de buffer(memória)
query = number of buffers gotten for consistent read memória consistente lida
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call Número de linhas processadas pelo comando.
********************************************************************************
SQL ID: 3k65pg76br3xc Plan Hash: 3482310901
SQL_ID: identificador do sql permite reconhecer a instrução SQL pelo código dela. Utilizado por advisors, relatórios AWR
Plan Hash: Identificador do plano de execução da query. Plano de execução é a forma que o Oracle encontrou de acessar os dados solicitados pela query. Esta forma é a melhor??? Nem sempre! Vamos verificar isso em um post específico.
SELECT SUM(ROUND(NVL(PARC.VLR_PARCELA,0),2))
FROM
LF_CIAP_PARCELA PARC WHERE PARC.REFERENCIA <= :B2 AND PARC.ID_CIAP = :B1
Esta é a query que mais demorou a execução
Veja os tempos dela:
call count cpu elapsed disk query current rows
——- —— ——– ———- ———- ———- ———- ———-
Parse 1 0.00 0.00 0 0 0 0
Execute 13681 17.27 17.20 0 0 0 0
Fetch 13681 6.87 56.20 4765 83174 0 13681
——- —— ——– ———- ———- ———- ———- ———-
total 27363 24.14 73.41 4765 83174 0 13681
Fazendo uma análise podemos verificar que a query executou 13681 vezes e demorou 17,20 segundos para isso.
Também conseguimos analisar que o maior tempo neste caso foi o fetch. Fetch é um processo que está ligado diretamente a uma instrução SELECT, sendo ele o responsável por “trazer” os dados para tela, demonstrar os dados.
Sendo assim, do trace acima podemos afirmar que a query que mais demorou no banco gastou um tempo total de 73,41 segundos.
Claro que ainda pode ser cedo para afirmar com toda certeza, mas existe grande chance de não ser o banco de dados o culpado pelo grande atraso citado pela nossa usuária.
Para garantir isso precisaríamos olhar duas sessões muito importantes do trace:
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
Estas duas sessões dentro do trace serão tratadas no próximo post de forma detalhada e assim conseguiremos ter a exata noção de qual o tempo gasto em banco de dados para toda a execução do processo.
Conseguiu entender a idéia? Ora um usuário fala que o Banco é o culpado e que tudo está lento!
Precisamos então verificar se realmente é o banco de dados o maior vilão. Para isso nada melhor do que ver e responder a seguinte questão:
Do tempo total do processo (geração do relatório), quanto tempo temos de banco de dados??
Com isto evidenciará que talvez a culpa esteja na rede, no servidor de aplicação, no terminal do usuário.
Este é um exemplo de situação corriqueira onde conseguimos Demonstrar talento quando tudo “tá lento”.
Por hoje é isso! Gostaria de ver mais comentários a respeito dos assuntos postados, do blog, enfim, gostaria muito da sua participação.
Ahhh! Já ia quase esquecendo, ajude a divulgar, participe da FANPAGE facebook.com\raulfdba (é raulfdba mesmo, pois já existe um rauldba, em Portugal eu acho.)
Não perca os próximos posts de fechamento do caso da usuária Elisângela.
Grande abraço e FOCO! Foco na Meta!!!
