Otimização de parsing usando bind variables

Hoje vou apresentar a vocês um dos grandes responsáveis pela degradação de performance nos bancos de dados Oracle: trata-se do excessivo uso de hard parsing,  ou seja, a pequena reusabilidade dos planos nas diretivas SQL.

Para quem não conhece, o hard parse ocorre quando o banco vê uma query pela "primeira vez" e não tem uma estratégia definida sobre como irá acessar os dados. Logo, ele precisa analisar todas as combinações possíveis de métodos de acesso para obter aquela informação solicitada. Esta análise inclui, mas não está limitada a, definir a ordem de join das tabelas, análise de estatísticas (de tabelas e do sistema), a decisão de fazer a leitura por índices ou full table scans (FTS), a reescrita da query para uma equivalente mais rápida, criar ou não tabelas intermediárias para views, enfim, uma infinidade de operações que, quando mais complicada for a query, mas possibilidades existem e mais recursos são consumidos para estabelecer este plano de execução.

Uma vez estabelecido, o plano de execução tende a ser reutilizado todas as vezes que a query for executada, desde que este plano consiga se manter em memória. Acontece que, se muitas querys distintas forem executadas, a área disponível para armazenamento de planos na shared pool pode não ser suficiente, e os planos mais antigos começam a ser descartados. Numa situação destas, um plano previamente estabelecido pode ser sobrescrito por um plano de outra query e ao reexecutarmos uma query mais antiga ela acabará tendo que passar pelo processo de hard parse novamente (e por sua vez sobrescrevendo o plano de outra query).

Agora, o que determina a quantidade de hard parsing no banco, e como evitar? Bom, primeiro, um dos critérios é o tamanho em memória da shared pool. Esta área armazena todos os planos atualmente disponíveis para o Oracle. Não vou entrar em detalhes neste momento sobre quanta memória é o ideal para esta área, pois para os fins deste artigo é o critério seguinte que nos interessa: a quantidade de querys distintas que existem no banco em um dado momento.

Para responder esta questão a primeira coisa que precisamos levar em conta é: como o Oracle faz para identificar que uma query já existe ou não na shared pool? E a reposta é, de modo geral, com uma comparação textual exata da query solicitada com as querys disponíveis na shared pool. Digo de modo geral porque este comportamento pode ser modificado com o parâmetro de sistema cursor_sharing (voltarei a falar sobre ele adiante).

Suponha por exemplo, que você executou a query a seguir:

select * from t where x = 1;

E em seguida executou a query:

select  * from t where x = 1;

A primeira vista as duas querys podem parecer iguais, mas na segunda eu incluí um espaço a mais antes do asterisco (*). Isto por si só já é o suficiente para que a segunda query falhe na comparação textual com  a primeira, e portanto as duas serão submetidas a um hard parse.

Este conceito fica mais evidenciado quando estamos lidando com SQL dinâmico, pois é muito comum as pessoas codificarem a passagem dos valores para a query utilizando a concatenação de valores:

execute immediate 'select * from t where x = ' || valor;

Agora considere este código dentro de uma stored procedure que recebe a variável 'valor' como parâmetro. Esta SP vai ter o poder de gerar infinitos cursores, pois cada valor concatenado vai forçar uma query nova (vai falhar na comparação textual) e toda chamada desta SP, além de passar por um hard parse, vai ainda retirar um cursor mais antigo da shared pool que poderia ser reaproveitado. Ou seja, além da lentidão do parse, corremos o risco de destruir a shared pool inteira, se por exemplo, executarmos esta SP dentro de um loop.

No próximo artigo irei apresentar um caso de performance de um código com bind variables contra um código sem binds. Fiquem ligados!

Os melhores blogs sobre Oracle

Sei que o título parece um pouco pretensioso, mas o objetivo deste post é listar os melhores blogs que existem tratando do assunto banco de dados Oracle ou PL/SQL. A idéia é manter a lista sempre atualizada acrescentando sites a medida do necessário.

Estou fazendo isso principalmente porque no meu recente crash de HD perdi muita informação, sendo meus bookmarks uma parte disso. Portanto, decidi manter meus bookmarks oficialmente online neste post, e de quebra posso ajudar alguém que esteja procurando novas fontes de informação.

Se alguém tiver uma sugestão de blogs fique a vontade para postar nos comentários abaixo que eu adicionarei a lista oficial.

Melhores blogs sobre banco de dados Oracle

Internacionais


Inside the Oracle Optimizer - Removing the black magic (Maria Colgan)
Oracle Scratchpad (Jonathan Lewis)
Richard Foote’s Oracle Blog
Steven Feuerstein
Structured Data (Greg Rahn)
The Tom Kyte Blog
oracle-developer.net (Adrian Billington)

Nacionais

ORA-01000 cc – miltonbastos.com

Nota: a lista está longe de estar completa, mas estou postando ela agora justamente para divulgar e angariar sugestões de novos blogs com os leitores.

Utilizando o tkprof para localizar hotspots de SQL

Finalmente, dando continuidade ao post sobre Metodologia de tuning parte 3, vou falar um pouco mais sobre como funciona a ferramenta tkprof para localizar hotspots de SQL.

Como havia dito anteriormente, infelizmente eu tive problemas com o HD da minha máquina e perdi a versão anterior deste artigo. Então, para poder publicá-lo no menor tempo possível resolvi ao invés de utilizar o exemplo complexo que eu havia elaborado, reaproveitar o código de exemplo do post Caso de Performance 2 - Tabelas Temporárias, com algumas pequenas adaptações. Na realidade, o código que utilizarei neste post pouco importa, o que vale é a técnica de utilização da ferramenta.

Dito isto, as adaptações realizadas no código original foram as seguintes: primeiro, eu transformei os blocos anônimos em duas stored procedures. A primeira, slow_proc, é o método lento, utilizando tabelas temporárias. A segunda, fast_proc, é o método rápido, utilizando arrays. Além disso, para simplificar o trabalho, coloquei as etapas de criação do ambiente em um arquivo texto chamado prepara_trace.sql que eu irei invocar para zerar o ambiente em cada etapa do tutorial. Segue seu conteúdo na íntegra:

drop table heap_table;

create table heap_table(x number);

drop table temp_table;

create global temporary table temp_table(x number);

create or replace procedure slow_proc as
  t number := dbms_utility.get_time;
  procedure lp_dummy is
  begin
    insert into heap_table
    select * from temp_table;
  end;
begin
  for r in (select rownum from dual connect by level <= 1000)
  loop
    delete temp_table;
    insert into temp_table
    select rownum from dual connect by level <= 100;
    lp_dummy;
  end loop;
  dbms_output.put_line('hsecs=' || (dbms_utility.get_time - t));
end;
/

create or replace procedure fast_proc as
  t number := dbms_utility.get_time;
  type typ_heap is table of heap_table%rowtype index by pls_integer;
  a_heap typ_heap;
  procedure lp_dummy is
    begin
    forall i in a_heap.first .. a_heap.last
    insert into heap_table values a_heap(i);
  end;
begin
  for r in (select rownum from dual connect by level <= 1000)
  loop
    select rownum bulk collect into a_heap
    from dual connect by level <= 100;
    lp_dummy;
  end loop;
  dbms_output.put_line('hsecs=' || (dbms_utility.get_time - t));
end;
/

Agora, para começar, lembre-se de verificar o diretório de destino do trace no sqlplus com o comando:

show parameter user_dump_dest

Além disso, você vai precisar se conectar com o usuário oracle ou um usuário que pertence ao grupo dba para poder ler o arquivo do trace.

Feito estes preparativos vamos ao processo:

$ sqlplus dani/dani

SQL*Plus: Release 10.2.0.1.0 - Production on Sun Dec 4 21:52:11 2011

Copyright (c) 1982, 2005, Oracle.  All rights reserved.


Connected to:
Oracle Database 10g Express Edition Release 10.2.0.1.0 - Production

SQL> set serveroutput on
SQL> @/tmp/prepara_trace

Table dropped.


Table created.


Table dropped.


Table created.


Procedure created.


Procedure created.


SQL> alter session set tracefile_identifier = 'slow';

Session altered.

SQL> alter session set sql_trace = true;

Session altered.

SQL> call slow_proc();
hsecs=235

Call completed.

SQL> alter session set sql_trace = false;

Session altered.

SQL> alter session set tracefile_identifier = 'fast';

Session altered.

SQL> alter session set sql_trace = true;

Session altered.

SQL> call fast_proc();
hsecs=38

Call completed.

SQL> alter session set sql_trace = false;

Session altered.

SQL> exit

Agora temos 2 arquivos de trace, correspondentes a cada uma das execuções. Vamos analisá-los com o tkprof:

$ ls -ltrh | tail -n 2
-rw-r----- 1 oracle dba 283K 2011-12-04 21:53 xe_ora_2946_slow.trc
-rw-r----- 1 oracle dba 236K 2011-12-04 21:54 xe_ora_2946_fast.trc

$ tkprof xe_ora_2946_slow.trc slow.txt

TKPROF: Release 10.2.0.1.0 - Production on Sun Dec 4 21:57:26 2011

Copyright (c) 1982, 2005, Oracle.  All rights reserved.


$ tkprof xe_ora_2946_fast.trc fast.txt

TKPROF: Release 10.2.0.1.0 - Production on Sun Dec 4 21:57:39 2011

Copyright (c) 1982, 2005, Oracle.  All rights reserved.

Primeiro, vamos analisar o arquivo slow.txt. Uma maneira bem tranquila para se localizar os comandos SQL que estão tomando mais tempo é observar as linhas de sumário para total - elapsed, ou seja, o tempo real decorrido de execução do comando. Com o comando grep do Linux/Unix podemos listar rapidamente as linhas de totais:

$ grep total slow.txt
total        1      0.00       0.00          0          0          0           0
total        4      0.00       0.00          0          0          0           2
total        2      0.14       0.19          0          0          0           0
total        4      0.00       0.00          0          4          0           1
total        3      0.00       0.00          0          2          0           0
total        3      0.00       0.00          0          2          0           1
total        3      0.00       0.00          0          2          0           1
total        3      0.00       0.00          0          1          0           1
total        3      0.00       0.00          0          2          0           0
total        4      0.00       0.00          0          4          0           1
total        3      0.00       0.00          0          1          0           0
total        1      0.00       0.00          0          0          0           0
total       13      0.00       0.00          0          0          0        1000
total        6      0.00       0.00          0          2          0           0
total     1001      1.08       1.37          0      31947     103235       99900
total        5      0.00       0.00          0          4          0           0
total     1001      0.33       0.29          0       1183       3018      100000
total        3      0.00       0.00          0          3          0           1
total     1001      0.46       0.41          0      32384       2869      100000
total      108      0.00       0.00          0         92          0          27
total       32      0.00       0.00          0         50         16          16
total       32      0.00       0.00          0         80         16          16
total        2      0.00       0.00          0          0          0           0
total        9      0.15       0.20          0          0          0           2
total     3229      1.90       2.09          0      65763     109154      300965

Todas as linhas mostradas representam o sumário de um comando SQL contido no arquivo, com exceção das duas últimas que representam os sumários do tkprof. Agora, eu falei que era importante olhar para as colunas elapsed, certo? Para recordar, estas linhas "total" que mostramos com o comando anterior fazem parte de tabelas como esta aqui:

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute   1000      1.08       1.36          0      31947     103235       99900
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total     1001      1.08       1.37          0      31947     103235       99900

No caso, destaquei em negrito a linha "total" na tabela acima e na lista anterior para você se situar melhor onde quero chegar. A coluna 4 da lista de resultado do grep corresponde exatamente ao tempo elapsed. Então ao olhar esta coluna sabemos exatamente quais são os comandos SQL que devemos buscar no arquivo do trace baseado nos seus tempos. Se você abrir o arquivo slow.txt e buscar pelo tempo 1.37 vai cair nesta tabela e vai descobrir que ela corresponde à linha delete temp_table da procedure slow_proc.

Agora repare que interessante: com exceção da última linha, que corresponde ao sumário, esta é a linha que mais consome tempo, ou seja: perdemos mais tempo limpando nossa tabela de trabalho do que fazendo qualquer processamento útil para nossa "regra de negócio". Sei que é um exemplo artificial, mas na vida real já vi acontecerem situações similares.

E para você que teve paciência de ler até aqui vai um macete de presente. Primeiro, observe que este é um trace pequeno e mesmo assim tem 25 linhas total para serem avaliadas. Imagine uma procedure "de verdade", com dezenas de linhas e de chamadas a outras procedures... vai ser um caos localizar manualmente estas querys, certo? Então fique de olho no comando a seguir:

$ grep total slow.txt | awk '{if($4>0.1) {print $4}}'
0.19
1.37
0.29
0.41
0.20
2.09

Qual é a mágica? Utilizando o comando awk, adicionei um filtro na coluna 4 (variável $4) para mostrar apenas os valores que forem maiores que 0,1 . Assim eu estabeleço um critério sobre quais SQL eu quero avaliar - apenas aqueles que gastaram mais que um tempo x. Se você quiser mostrar a linha inteira, pode substituir o print $4 por print $0:

$ grep total slow.txt | awk '{if($4>0.1) {print $0}}'
total        2      0.14       0.19          0          0          0           0
total     1001      1.08       1.37          0      31947     103235       99900
total     1001      0.33       0.29          0       1183       3018      100000
total     1001      0.46       0.41          0      32384       2869      100000
total        9      0.15       0.20          0          0          0           2
total     3229      1.90       2.09          0      65763     109154      300965

Aí, tendo em mãos esta lista de valores, você pode facilmente pegar seu editor de texto favorito e fazer uma busca textual pelo valor da coluna 4 que encontrará a tabela de sumário. Logo acima desta tabela estará a query responsável por aquele tempo.

Enfim, esta é a técnica que eu gostaria de mostrar para identificar hotspots de SQL em um arquivo de trace. É de certa forma bastante rudimentar mas já me quebrou o galho muitas vezes. Apenas gostaria de acrescentar mais uma informação para aqueles que utilizam RedHat ou derivados, adicione a função strtonum() na coluna $4 ao fazer a comparação com o valor de limite:

$ grep total slow.txt | awk '{if(strtonum($4)>0.1) {print $0}}'

 E para finalizar, vou mostrar o resultado do grep no arquivo fast.txt:

$ grep total fast.txt | awk '{if($4>0.1) {print $0}}'
total     2001      0.18       0.18          0          0          0      100000
total     3054      0.27       0.26          0        210       2240      201009

Apenas 2 ocorrências, sendo que uma delas é o sumário... definitivamente, remover o overhead do tratamento das temporárias deixou o código muito mais level e eficiente!

Aconselho você a executar este exemplo em casa e conferir os resultados. Tem muita informação nos arquivos de trace e tkprof que eu não consigo cobrir em um único post, então aproveite para tirar dúvidas na seção de comentários abaixo. Até a próxima!

Problemas técnicos e Enquete

Boa tarde pessoal. Gostaria de publicar apenas uma rápida nota avisando que estou passando por alguns problemas técnicos com meu notebook onde eu estava rodando os códigos de exemplo. Basicamente o HD dele apresentou defeito e junto com ele foi o novo artigo que eu estava preparando sobre o tkprof. Em termos de conteúdo não se perdeu muito, pois isso ainda está fresco na minha cabeça... o problema maior vai ser arrumar tempo para organizar o setup de novo e também trocar o HD defeituoso.

Enquanto isso se resolve, gostaria de chamar a atenção de vocês para uma enquete que eu coloquei na barra lateral do blog, sobre a expectativa de quais artigos eu devo me concentrar no futuro. Por favor votem, pois assim posso dar um direcionamento melhor ao conteúdo de maneira a agradar a todos os leitores.

No mais, espero que até o fim de semana eu já tenha a estrutura para continuar o ritmo normal de publicações. Fiquem ligados!

Metodologia para Tuning de Procedimentos - Parte 3

Dando continuidade a série de posts sobre metodologia de tuning hoje vou falar sobre as estratégias que dispomos para identificar os hotspots, ou seja, os pontos que estão gastando mais tempo do nosso processo e que portanto necessitam de ajustes.

A ferramenta primordial para localizar estes pontos é o SQL Trace. Este é um recurso do banco de dados Oracle que habilita a gravação de um arquivo de log com todas as operações realizadas dentro de uma determinada sessão (ou de várias sessões, no caso de uma conexão MTS). O arquivo de log gerado pelo SQL trace fica sempre armazenado no sistema de arquivos do servidor, dentro da pasta apontada pelo parâmetro user_dump_dest. Abaixo mostro duas formas de recuperar o valor deste parâmetro:


paulo@hitomi:~$ sqlplus paulo/paulo

SQL*Plus: Release 11.2.0.2.0 Beta on Sat Nov 26 21:23:12 2011

Copyright (c) 1982, 2010, Oracle.  All rights reserved.


Connected to:
Oracle Database 11g Express Edition Release 11.2.0.2.0 - 64bit Beta

SQL> show parameter user_dump_dest

NAME     TYPE VALUE
------------------------------------ ----------- ------------------------------
user_dump_dest     string /u01/app/oracle/diag/rdbms/xe/
XE/trace
SQL> select value from v$parameter where name = 'user_dump_dest';

VALUE
--------------------------------------------------------------------------------
/u01/app/oracle/diag/rdbms/xe/XE/trace

SQL> 

E, para habilitar o SQL trace da sessão atual, basta executar:

SQL> alter session set sql_trace = true;

Session altered.

SQL> select 1 from dual;

1

----------

1

SQL> alter session set sql_trace = false;

Session altered.

SQL> 

Um arquivo .trc será gerado no diretório de user_dump_dest com o resultado do trace desta sessão. Se você for neste diretório e tentar localizar o arquivo pode abri-lo com um editor de textos comum, como o vi ou o nano. Pode a principio ser um pouco complicado localizar o arquivo, pois é comum que o banco armazene traces automáticos para seus processos internos, então é um bom costume criar um identificador para o arquivo para facilitar sua busca.

Fazemos isso usando outra variável de sessão, o tracefile_identifier. Exemplo de uso:

SQL> alter session set tracefile_identifier = 'paulo';

Session altered.

SQL> alter session set sql_trace = true;

Session altered.

SQL> select 1 from dual;

1

----------

1

SQL> alter session set sql_trace = false;

Session altered.

SQL> 

Agora, basta procurar por todos os arquivos com este identificador no diretório dos arquivos de trace:

oracle@hitomi:/u01/app/oracle/diag/rdbms/xe/XE/trace$ ll *paulo*

-rw-r----- 1 oracle dba 2351 2011-11-26 21:34 XE_ora_25084_paulo.trc

-rw-r----- 1 oracle dba   82 2011-11-26 21:34 XE_ora_25084_paulo.trm

No caso, o arquivo XE_ora_25084_paulo.trc é o trace gerado para a sessão acima.

Ok, agora que temos o trace como utilizá-lo? Uma rápida vista neste arquivo mostrará que mesmo uma sessão tão simples quanto a que apresentei neste exemplo vai popular o arquivo com uma infinidade de comandos que a princípio vão parecer praticamente "criptografados". A verdade é que este arquivo possui uma estrutura bastante lógica, e é possível sim ler ele diretamente para buscar informações. No entanto, não é o nosso neste momento aprender a interpretá-lo, por isso vou passar direto para mostrar a próxima ferramenta que vai simplificar bastante este trabalho. Trata-se do tkprof.

O tkprof é um utilitário que faz a conversão do arquivo de trace em um relatório mais "legível" para os seres humanos. Estaremos utilizando ele bastante sempre que houver a necessidade de localizar hotspots de SQL em nossos procedimentos. No caso, isto se deve ao fato de que o trace por si só coleta informação de querys, e não de PL/SQL, o que pode ser uma limitação aparentemente inconveniente, mas existem outras formas de obter esta informação. De qualquer forma, o tkprof é uma ferramenta fundamental para localizar querys problemáticas dentro de hierarquias de procedimentos e funções. Vamos ao seu uso:

oracle@hitomi:/u01/app/oracle/diag/rdbms/xe/XE/trace$ tkprof XE_ora_25084_paulo.trc paulo.txt

TKPROF: Release 11.2.0.2.0 - Development on Sat Nov 26 21:45:40 2011

Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved.

oracle@hitomi:/u01/app/oracle/diag/rdbms/xe/XE/trace$

Simples assim! Passamos o arquivo de trace como entrada e um arquivo txt como saída. A resposta é o arquivo txt apresentando um relatório muito mais legível do que o trace puro. Abaixo, coloco na íntegra  o relatório do trace que gerei nos passos acima:

oracle@hitomi:/u01/app/oracle/diag/rdbms/xe/XE/trace$ cat paulo.txt

TKPROF: Release 11.2.0.2.0 - Development on Sat Nov 26 21:45:40 2011

Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved.

Trace file: XE_ora_25084_paulo.trc

Sort options: default

********************************************************************************

count    = number of times OCI procedure was executed

cpu      = cpu time in seconds executing 

elapsed  = elapsed time in seconds executing

disk     = number of physical reads of buffers from disk

query    = number of buffers gotten for consistent read

current  = number of buffers gotten in current mode (usually for update)

rows     = number of rows processed by the fetch or execute call

********************************************************************************

SQL ID: 1hgzr5xxpmt7h Plan Hash: 0

alter session set sql_trace = true

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        0      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           0

Fetch        0      0.00       0.00          0          0          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        1      0.00       0.00          0          0          0           0

Misses in library cache during parse: 0

Misses in library cache during execute: 1

Optimizer mode: ALL_ROWS

Parsing user id: 48  

********************************************************************************

SQL ID: 520mkxqpf15q8 Plan Hash: 1388734953

select 1 

from

 dual

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           0

Fetch        2      0.00       0.00          0          0          0           1

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        4      0.00       0.00          0          0          0           1

Misses in library cache during parse: 0

Optimizer mode: ALL_ROWS

Parsing user id: 48  

Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation

---------- ---------- ----------  ---------------------------------------------------

         1          1          1  FAST DUAL  (cr=0 pr=0 pw=0 time=8 us cost=2 size=0 card=1)

********************************************************************************

SQL ID: 988n7wn97ptgf Plan Hash: 0

alter session set sql_trace = false

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.00          0          0          0           0

Execute      1      0.00       0.00          0          0          0           0

Fetch        0      0.00       0.00          0          0          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        2      0.00       0.00          0          0          0           0

Misses in library cache during parse: 1

Optimizer mode: ALL_ROWS

Parsing user id: 48  

********************************************************************************

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        2      0.00       0.00          0          0          0           0

Execute      3      0.00       0.00          0          0          0           0

Fetch        2      0.00       0.00          0          0          0           1

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        7      0.00       0.00          0          0          0           1

Misses in library cache during parse: 1

Misses in library cache during execute: 1

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        0      0.00       0.00          0          0          0           0

Execute      0      0.00       0.00          0          0          0           0

Fetch        0      0.00       0.00          0          0          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        0      0.00       0.00          0          0          0           0

Misses in library cache during parse: 0

    3  user  SQL statements in session.

    0  internal SQL statements in session.

    3  SQL statements in session.

********************************************************************************

Trace file: XE_ora_25084_paulo.trc

Trace file compatibility: 11.1.0.7

Sort options: default

       1  session in tracefile.

       3  user  SQL statements in trace file.

       0  internal SQL statements in trace file.

       3  SQL statements in trace file.

       3  unique SQL statements in trace file.

      47  lines in trace file.

      17  elapsed seconds in trace file.

oracle@hitomi:/u01/app/oracle/diag/rdbms/xe/XE/trace$ 

Como você pode ver, no relatório do tkprof estão todos os comandos SQL executados a partir do início do trace. Num procedimento real, as tabelas de resumo apresentadas (com as contagens de parse, execute  e fetch) vão acumular os dados das n-vezes que a determinada query for executada. Por exemplo, se eu executasse 100 vezes a query 'select 1 from dual', todas as 100 estariam agregadas na mesma tabela de sumário.

Isto é muito útil para localizar quais querys estão consumindo mais tempo de execução, baseado no seu tempo total decorrido (coluna elapsed do relatório). Uma maneira fácil de analisar este arquivo é executar uma busca por todas as linhas contendo a palavra 'total':

oracle@hitomi:/u01/app/oracle/diag/rdbms/xe/XE/trace$ grep total paulo.txt 

total        1      0.00       0.00          0          0          0           0

total        4      0.00       0.00          0          0          0           1

total        2      0.00       0.00          0          0          0           0

total        7      0.00       0.00          0          0          0           1

total        0      0.00       0.00          0          0          0           0

oracle@hitomi:/u01/app/oracle/diag/rdbms/xe/XE/trace$ 

No caso, este arquivo não é um bom exemplo porque todas as querys foram instantâneas, mas num procedimento mais complexo você poderia localizar exatamente quais são as querys mais pesadas com este comando. No próximo post trarei um exemplo melhor para mostrar como funciona esta técnica.

Metodologia para Tuning de Procedimentos - Parte 2

No post anterior eu falei sobre o primeiro requisito para uma tarefa de tuning: a reprodutibilidade. Dando continuidade ao assunto, hoje vou abordar o segundo requisito: o objetivo. Toda tarefa de tuning necessita ter muito bem estabelecido o seu objetivo logo no início do processo. Eu sempre pergunto para as pessoas "Qual é a meta para este procedimento?", ou seja, qual é o tempo de resposta esperado como resultado da tarefa de tuning?

Estabelecer este tempo logo no início evita que seja gasto um esforço muito grande para otimizar o processo além do necessário e, digo isso principalmente porque, considerando que estamos falando de um processo complexo, sempre é possível extrair mais performance. O grande problema é o nível de esforço que vai ser gasto para obter as melhorias sucessivas, pois a cada nível de melhoria a tendência é que o processo para obter melhora seja mais complexo e mais demorado. Fundamentalmente, encontrar um equilibro entre objetivo de tuning e esforço é o segredo do tuning bem sucedido.

Algumas vezes o objetivo não está bem definido quando nós recebemos a tarefa, e é aí que ter feito todo o preparo que eu comentei sobre a reprodutibilidade vai entrar no jogo. Primeiro executamos o processo sem nenhuma intervenção para obter uma baseline na qual iremos nos basear durante todo o trabalho. Em alguns casos isso não é possível, como por exemplo, eu já recebi algumas tarefas onde a especificação dizia algo parecido com "este processo não roda mais... leva horas e não termina". Neste tipo de situação a baseline pode ser estabelecida em um processo parcial. Existem várias formas para fazer isto e tratarei de comentar sobre isso adiante.

Se você conseguir estabelecer a baseline no processo completo melhor, porém em processos muito grandes, ou mesmo, "infinitos", podemos utilizar as seguintes abordagens: 1) gerar um volume de dados de entrada menor para o processo (assumindo que estes dados são estatisticamente relevantes); 2) dividir o processo em etapas e analisando cada uma delas de forma independente ou; 3) utilizar o recurso de amostragem do Oracle (e ele se preocupa em reduzir o volume de dados por você).

Sobre o recurso de amostragem, talvez um recurso que poucos conheçam, trata-se da clausula SAMPLE do SELECT. Observe:


oracle@hitomi:~$ sqlplus paulo/paulo

SQL*Plus: Release 11.2.0.2.0 Beta on Sat Nov 26 13:45:03 2011

Copyright (c) 1982, 2010, Oracle.  All rights reserved.


Connected to:
Oracle Database 11g Express Edition Release 11.2.0.2.0 - 64bit Beta

SQL> create table t as select rownum x from dual connect by level <= 100;

Table created.

SQL> select count(*) from t;

  COUNT(*)
----------
       100

SQL> select count(*) from t sample(10);

  COUNT(*)
----------
12

SQL> /

  COUNT(*)
----------
7

SQL> /

  COUNT(*)
----------
4

SQL> /

  COUNT(*)
----------
11

SQL> select * from t sample(10);

X
----------
8
15
22
30
76
94

6 rows selected.

SQL>

Neste exemplo, foi criada uma tabela t com 100 linhas. Em seguida, demonstro o uso da cláusula sample com uma amostragem de 10%. Note que, por ser um conjunto de dados pequenos, existe uma grande variação no número de linhas retornadas. Para conjuntos de dados maiores esta cláusula tende a representar subconjuntos bastante significativos.

A grande vantagem do seu uso, também, é o fato de que você não precisa modificar a sua massa de dados de origem e consegue reduzir o tempo de execução necessário para cada teste de alteração no procedimento em que se está fazendo o tuning.

Uma vez estabelecidos os critérios de reprodutibilidade, o objetivo do tuning e a baseline de referência, seja esta para a massa de dados completa ou parcial, podemos então partir efetivamente para a tarefa de tuning.

Nesta próxima etapa precisamos tomar o cuidado de manter um controle rigoroso das alterações que fazemos, alterando de preferência uma coisa de cada vez. As vezes é muito tentador fazer várias modificações ao mesmo tempo, porém corremos sempre o risco de perder a referência e ter que voltar atrás várias vezes até descobrir qual alteração melhorou e qual piorou a performance do processo.

Eu recomendo o uso de uma planilha do Excel como controle de execuções, alterações, efeitos esperados e efeitos obtidos. Para não tornar este post demasiadamente extenso, continuarei a falar sobre isso na parte 3 desta série... fiquem ligados!

Metodologia para Tuning de Procedimentos - Parte 1

É comum no meu dia-a-dia receber chamados para a otimização de um determinado procedimento ou query que está demasiado lento. Para realizar uma tarefa como esta, o banco nos oferece diversas ferramentas que facilitam bastante a nossa vida, porém sem uma metodologia adequada elas podem não só se mostrarem ineficientes como também prejudicar o processo como um todo.

É por este motivo que eu gostaria de iniciar hoje uma discussão sobre uma metodologia para otimização, focando principalmente em código PL/SQL, mas também comentando alguns aspectos sobre o tuning de querys. Esta é a parte 1 de uma série de artigos que virão na sequencia para comentar sobre este tema.

O primeiro critério para um tuning bem sucedido é a reprodutibilidade. De modo geral eu costumo gastar um bom tempo na preparação do ambiente para que eu possa reproduzir a situação-problema inúmeras vezes. Dependendo do processo isso vai envolver apagar dados de tabelas chave, salvar valores de colunas numa tabela de backup, truncar tabelas inteiras... enfim, é importante mapear todas as condições para um restart limpo e deixar elas a mão em um script de limpeza (pode ser o próprio script de execução da rotina), pois a cada modificação do cenário é necessário recomeçar do zero ou corremos o risco de obter uma falsa sensação de objetivo cumprido e o processo voltar a dar problema nas mãos do usuário.

Uma ressalva importante na questão da reprodutibilidade é que você não pode ignorar as características do banco, ou seja, não se trata apenas de código pois algumas features fundamentais que fazem o banco Oracle ter uma performance excelente podem atrapalhar você na hora do tuning.

Vai ficar mais claro com um exemplo: suponha que o problema da sua query está diretamente relacionada a um excesso de I/O físico (physical reads). No caso, ao executar ela pela primeira vez ela estará bastante lenta... aí você modifica um ou outro código e bota ela para rodar de novo. Para sua surpresa a query executa quase instantâneamente! "Problema resolvido!" você pensa, mas pode estar muito enganado! Acontece que ao executar a primeira vez a query os blocos das tabelas estavam no disco e não na memória... um cache miss no db block cache então solicita a carga das tabelas para memória (este é um processo lento). Ao executar a segunda query, independente dela ser diferente ou não, seu tempo de acesso vai ser mais rápido porque o cache miss agora é um cache hit, ou seja, o banco vai acessar diretamente o dado das tabelas em memória e o gargalo do I/O físico vai aparentemente desaparecer, para voltar apenas quando os blocos em cache forem aged out (removidos).

Uma forma de se ver livre deste viés é fazer um flush do buffer cache:

Alter System Flush buffer_cache;

Porém jamais faça isso em produção, pois este comando não é nada seletivo e todos os blocos em memória são descarregados para o disco. Seus usuários agradecem!

Outro fator que pode impactar é o parsing da query. No Oracle existem duas formas de parse: o hard parse e o soft parse. No hard parse é feita a completa validação e avaliação da query, desde a elaboração do melhor plano de execução até a construção do result set. Este parse é bastante demorado em função de que diversos algoritmos são aplicados para escolher o plano ótimo. Por outro lado, o soft parse se baseia num plano de execução pronto e após uma validação mais rápida da query parte direto para a fase de execução (execute) e aquisição (fetch) dos dados. Por este motivo o soft parse é muito mais rápido e é sempre desejável.

Agora, sempre que uma query não está em memória o Oracle necessita fazer um hard parse, mas uma vez carregada ele vai fazer o soft parse sempre que possível. Portanto, ao executar pela segunda vez uma query a tendência é que ela seja mais rápida por não necessitar mais do parse completo. Mais uma vez existe um comando para eliminar este viés, que é:

Alter system flush shared_pool;

Estes dois comandos são um tanto radicais, pois ambos destroem completamente os dados carregados em memória. Por isto, não recomendo o seu uso exceto em ocasiões muito especiais. Além disto, existem algumas formas de contornar estas otimizações do Oracle de forma menos agressiva, como por exemplo, no caso do parsing, executar um gather stats da tabela alvo com o parametro no_invalidade=>false. Este parâmetro força a reavaliação dos planos de todas as querys que dependem da tabela. Ou ainda, se o parâmetro cursor_sharing da instância estiver setado para exact, basta fazer uma modificação simples da query como inserir um espaço em branco ou modificar a caixa de uma letra que a query será tratada como uma query totalmente nova (a comparação das querys no Oracle é textual/binária).

No caso do db block cache, eu procuro nivelar o terreno para o tuning desconsiderando a primeira execução e utilizando como métrica sempre a segunda em diante. Existem algumas outras técnicas, mas para não me estender muito vou deixar para comentar sobre isso num post futuro.

Sumarizando então o tópico da reprodutibilidade, é importante garantir uma metodologia para executar o procedimento sempre nas mesmas condições, tanto em termos de dados como de infraestrutura de banco. Esta preocupação é necessária para termos uma baseline para trabalhar com a qual poderemos medir as influências das nossas alterações e identificar resultados positivos e negativos das intervenções. Existem alguns fatores externos que também devemos sempre procurar minimizar, como por exemplo, a concorrência, mas nem sempre temos poder sobre isso... neste caso o importante é lembrar que ela existe e que o seu resultado nem sempre estará "puro".

Caso de Performance 2: Tabelas temporárias

Eu comentei no post inicial sobre performance em PL/SQL que as tabelas temporárias em Oracle, se mal utilizadas, podem causar uma grande dor de cabeça em termos de perfomance ruim. O caso que eu utilizei como referência, se vocês se recordam, foi o da passagem de parâmetros em massa para uma procedure, dentro de um loop.

Pode parecer um caso bastante específico, porém é uma prática comum em outros bancos onde esta estratégia não só é perfeitamente válida como também proporciona uma ótima performance. O caso em questão é que no Oracle existe uma alternativa melhor e mais performática, que é a passagem de valores múltiplos por arrays. Cabe aqui uma ressalva, que pelo fato de arrays serem estruturas de memória, não convém passar milhões de registros desta forma. De modo geral passamos no máximo algumas centenas ou poucos milhares de registros de uma vez só, visto que mais do que isso pode resultar em um grande consumo de memória pelo nosso processo. Já testemunhei casos extremos onde alocar um array para muitos registros derrubou o banco por consumo excessivo de memória.

Para estas situações onde se processam muitos milhares ou mesmo milhões de registros cabe sim o uso de tabelas temporárias, no entanto ainda fica o alerta para que este tipo de processamento jamais seja feito em loops com o uso de comandos DELETE para limpar a temporária entre cada passada.

Dito tudo isto, vamos ao exemplo do dia. Eu demorei um pouco para elaborar um caso para este exemplo justamente pela sua especificidade. De modo geral, minha intenção era elaborar uma situação onde: existe um loop externo que controla o processamento; a cada iteração deste loop é carregado um conjunto de dados em uma estrutura (tabela temporária ou array) e; finalmente, esta estrutura é processada em um subprocedimento. A idéia é avaliar o impacto de passar esta massa de dados para o subprocedimento através de uma tabela temporária e através de um array.

No exemplo o loop de controle está programado para 100 repetições e a cada loop são carregadas 100 linhas no "portador" (array ou tabela temporária). Para simplificar Aa etapa do processamento, é feita simplesmente a inserção destes dados em uma tabela física. Tomei o cuidado de no exemplo com array fazer o insert na tabela utilizando o comando FORALL para eliminar a influencia de trocas de contexto (comparativamente um FORALL equivale a um INSERT SELECT, pois ambos são resolvidos em apenas uma troca de contexto). O mesmo vale para a carga dos portadores: no caso da tabela temporária é feito um INSERT SELECT e para carga do array utilizo um BULK COLLECT.

Os tempos, mais uma vez, são representados em centésimos de segundo.

oracle@hitomi:~$ sqlplus paulo/paulo

SQL*Plus: Release 11.2.0.2.0 Beta on Wed Nov 23 13:15:34 2011

Copyright (c) 1982, 2010, Oracle. All rights reserved.

Connected to:

Oracle Database 11g Express Edition Release 11.2.0.2.0 - 64bit Beta

SQL> create global temporary table temp_table(x number);

Table created.

SQL> create table heap_table(x number);

Table created.

SQL> set serveroutput on

SQL> declare

2 t number := dbms_utility.get_time();

3 procedure lp_dummy is

4 begin

5 insert into heap_table

6 select * from temp_table;

7 end;

8 begin

9 for r in (select rownum from dual connect by level <= 100)

10 loop

11 delete temp_table;

12 insert into temp_table select rownum from dual connect by level <= 100;

13 lp_dummy;

14 end loop;

15 dbms_output.put_line('hsecs=' || to_char(dbms_utility.get_time()-t));

16 end;

17 /

hsecs=112

PL/SQL procedure successfully completed.

SQL> /

hsecs=116

PL/SQL procedure successfully completed.

SQL> /

hsecs=120

PL/SQL procedure successfully completed.

SQL> rollback;

Rollback complete.

SQL> declare

2 t number := dbms_utility.get_time();

3 type typ_heap is table of heap_table%rowtype index by pls_integer;

4 a_heap typ_heap;

5 procedure lp_dummy is

6 begin

7 forall i in a_heap.first .. a_heap.last

8 insert into heap_table values a_heap(i);

9 end;

10 begin

11 for r in (select rownum from dual connect by level <= 100)

12 loop

13 select rownum bulk collect into a_heap from dual connect by level <= 100;

14 lp_dummy;

15 end loop;

16 dbms_output.put_line('hsecs=' || to_char(dbms_utility.get_time()-t));

17 end;

18 /

hsecs=23

PL/SQL procedure successfully completed.

SQL> /

hsecs=26

PL/SQL procedure successfully completed.

SQL> /

hsecs=25

PL/SQL procedure successfully completed.

SQL>

Nitidamente a abordagem por arrays é significativamente mais rápida, sendo de 4 a 5 vezes mais rápida neste exemplo. Vale ressaltar que o grande impacto da abordagem por tabelas temporárias, além do tempo de delete, é o gasto de recursos inserindo undo e redo para estas operações, que literalmente são descartáveis.