Implementando e utilizando o PL/SQL Profiler

O Oracle Profiler é uma feature presente desde a versão 8i e através de sua utilização é possível verificar quais os objetos do banco de dados foram invocados e o tempo de duração de cada um durante a execução de um objeto PL/SQL.

O Profiler é um recurso muito útil quando necessitamos realizar uma análise de desempenho, pois conseguimos analisar todos os processos que estão sendo executados em paralelo ao processo principal.

Vamos descobrir mais deste ótimo recurso?

Primeiramente vamos criar a estrutura necessária para o Oracle Profiler através da exeução de dois srcipts que estão em $ORACLE_HOME/rdbms/admin, observe que utilizamos o “@?” pois representa o ORACLE_HOME.

SQL> @?/rdbms/admin/profload.sql
Pacote criado.
Concess?o bem-sucedida.
Sinonimo criado.
Biblioteca criada.
Corpo de Pacote criado.
Testing for correct installation
SYS.DBMS_PROFILER successfully loaded.
Procedimento PL/SQL concluido com sucesso.
SQL> @?/rdbms/admin/proftab.sql
drop table plsql_profiler_data cascade constraints
           *
ERRO na linha 1:
ORA-00942: a tabela ou view n?o existe
drop table plsql_profiler_units cascade constraints
           *
ERRO na linha 1:
ORA-00942: a tabela ou view n?o existe
drop table plsql_profiler_runs cascade constraints
           *
ERRO na linha 1:
ORA-00942: a tabela ou view n?o existe
drop sequence plsql_profiler_runnumber
              *
ERRO na linha 1:
ORA-02289: a sequencia n?o existe
Tabela criada.
Comentario criado.
Tabela criada.
Comentario criado.
Tabela criada.
Comentario criado.
Sequencia criada.

Observe que no segundo script houve alguns erros na remoção dos objetos pelo fato destes ainda não existirem na nossa base de dados e que podem ser ignorados.
Agora que já realizamos a implementação desta feature, vamos testar sua utilização primeiramente criando alguns objetos que servirão de apoio ao exemplo.

SQL> create table funcionario(cod number, nome varchar2(50));
Tabela criada.
SQL> create table empresa (cod number, fantasia varchar(100));
Tabela criada.
SQL> begin
        for x in 1..100 loop
                insert into funcionario values (x,'FUNCIONARIO '||x);
                DBMS_OUTPUT.put_line('Funcionario '||x||' cadastrado');
        end loop;
end;
/
Procedimento PL/SQL concluido com sucesso.
SQL> create or replace procedure insert_emp is
begin
        insert into empresa values (1,'ORACLE HOME');
        DBMS_OUTPUT.put_line('Empresa cadastrada');
end;
/
Procedimento criado.
SQL> create or replace procedure cadastrar is
begin
        insert_emp;
        insert_func;
end;
/
Procedimento criado.

Para iniciarmos e interrompermos a coleta basta executarmos os seguintes comandos antes e após a execução da nossa procedure.
DBMS_PROFILER.START_PROFILER(‘qualquer comentário para identificar esta execução’);

DBMS_PROFILER.STOP_PROFILER;
Vejamos,

SQL> execute DBMS_PROFILER.START_PROFILER('Exemplo Profiler Oracle Home');
Procedimento PL/SQL concluido com sucesso.
SQL> execute SYS.cadastrar;
Procedimento PL/SQL concluido com sucesso.
SQL> execute DBMS_PROFILER.STOP_PROFILER;
Procedimento PL/SQL concluido com sucesso.

O Profiler populou três tabelas com informações relacionadas.
PLSQL_PROFILER_RUNS contém as informações sobre cada vez que o profiler foi iniciado, incluindo o comentário passado na execução para identificação.
PLSQL_PROFILE_UNITS contém informações sobre o código PL/SQL executado. Cada procedimento, função, pacote terá sua própria linha nesta tabela.
PLSQL_PROFILE_DATA contém as linhas do código executado, o tempo de execução do código, entre outros.
Primeiramente vamos identificar o RUNID da nossa execução:

SQL> set lines 190
SQL> col RUN_COMMENT for a70
SQL> select runid, run_owner, run_date, run_comment from plsql_profiler_runs;
     RUNID RUN_OWNER                        RUN_DATE RUN_COMMENT
---------- -------------------------------- -------- ----------------------------------------------------------------------
         2 SYS                              19/12/11 Exemplo Profiler Oracle Home

Realizando um select na plsql_profiler_units especificando o RUNID da coleta desejada podemos identificar varios otras informações como objetos envolvidos, tipo do objeto e o UNIT_NUMBER, a partir do qual será possível aprofundar a análise.

SQL> select runid, unit_number, unit_type, unit_owner, unit_name, unit_timestamp
  2  from plsql_profiler_units
  3  where runid = &runid
  4  order by unit_number;
Informe o valor para runid: 2
antigo   3: where runid = &runid
novo   3: where runid = 2
     RUNID UNIT_NUMBER UNIT_TYPE                        UNIT_OWNER                       UNIT_NAME                        UNIT_TIM
---------- ----------- -------------------------------- -------------------------------- -------------------------------- --------
         2           1 PACKAGE BODY                     SYS                              DBMS_PROFILER                    03/08/07
         2           2 ANONYMOUS BLOCK                  <anonymous>                      <anonymous>                      00/00/00
         2           3 ANONYMOUS BLOCK                  <anonymous>                      <anonymous>                      00/00/00
         2           4 PROCEDURE                        SYS                              CADASTRAR                        19/12/11
         2           5 PROCEDURE                        SYS                              INSERT_EMP                       19/12/11
         2           6 PACKAGE BODY                     SYS                              DBMS_OUTPUT                      03/08/07
         2           7 PROCEDURE                        SYS                              INSERT_FUNC                      19/12/11
         2           8 ANONYMOUS BLOCK                  <anonymous>                      <anonymous>                      00/00/00
8 linhas selecionadas.

Note que nem todos os registro retornados nos interessam como os de UNIT_OWNER = , estes podem ser removidos da consulta ( AND UNIT_OWNER ” ).
Para iniciarmos a análise, partimos da procedure que executamos no início das atividades (UNIT_NUMBER=4) – (RUNID=2).

SQL> set lines 190
SQL> col TEXT for a70
SQL> select pu.unit_name, pd.line#, pd.total_occur passes, round(pd.total_time / 1000000000,5) total_time, us.text text
  2  from plsql_profiler_data pd, plsql_profiler_units pu, user_source us
  3  where pd.runid = &runid
  4  and pd.unit_number = &unit_number
  5  and pd.runid = pu.runid
  6  and pd.unit_number = pu.unit_number
  7  and us.name = pu.unit_name
  8  and us.line = pd.line#
  9  and us.type in ('PACKAGE BODY','PROCEDURE','FUNCTION');
Informe o valor para runid: 2
antigo   3: where pd.runid = &runid
novo   3: where pd.runid = 2
Informe o valor para unit_number: 4
antigo   4: and pd.unit_number = &unit_number
novo   4: and pd.unit_number = 4
UNIT_NAME                             LINE#     PASSES TOTAL_TIME TEXT
-------------------------------- ---------- ---------- ---------- ----------------------------------------------------------------------
CADASTRAR                                 1          0          0 procedure cadastrar is
CADASTRAR                                 5          2     ,00001       insert_emp;
CADASTRAR                                 6          2     ,00004       insert_func;
CADASTRAR                                 8          1          0 end;

Podemos verificar que a procedure CADASTRAR chama 2 novas procedures, já listadas na consulta acima, incluindo o tempo de execução destas onde temos a INSERT_FUNC como mais demorada ,00004
Agora analisando a procedure mais custosa (INSERT_FUNC), cujo UNIT_NUMBER é 7 podemos identificar a causa desta demora e partirmos em busca de uma solução.

SQL> select pu.unit_name, pd.line#, pd.total_occur passes, round(pd.total_time / 1000000000,5) total_time, us.text text
  2  from plsql_profiler_data pd, plsql_profiler_units pu, user_source us
  3  where pd.runid = &runid
  4  and pd.unit_number = &unit_number
  5  and pd.runid = pu.runid
  6  and pd.unit_number = pu.unit_number
  7  and us.name = pu.unit_name
  8  and us.line = pd.line#
  9  and us.type in ('PACKAGE BODY','PROCEDURE','FUNCTION');
Informe o valor para runid: 2
antigo   3: where pd.runid = &runid
novo   3: where pd.runid = 2
Informe o valor para unit_number: 7
antigo   4: and pd.unit_number = &unit_number
novo   4: and pd.unit_number = 7
UNIT_NAME                             LINE#     PASSES TOTAL_TIME TEXT
-------------------------------- ---------- ---------- ---------- ----------------------------------------------------------------------
INSERT_FUNC                               1          0          0 procedure insert_func is
INSERT_FUNC                               5        101     ,00026       for x in 1..100 loop
INSERT_FUNC                               6        100     ,01423               insert into funcionario values (x,'FUNCIONARIO '||x);
INSERT_FUNC                               7        100     ,00084               DBMS_OUTPUT.put_line('Funcionario '||x||' cadastrado');
INSERT_FUNC                              10          1          0 end;

Para efetuarmos a limpeza das tabelas do profiler basta executarmos:

SQL> delete from plsql_profiler_data;
234 linhas deletadas.
SQL> delete from plsql_profiler_units;
8 linhas deletadas.
SQL> delete from plsql_profiler_runs;
1 linha deletada.
SQL> commit;
Commit concluido.
88x31 Implementando e utilizando o PL/SQL Profiler
O artigo: Implementando e utilizando o PL/SQL Profiler escrito por Anderson Graf (Admin) foi licenciado com uma Licenca Creative Commons Attribution-NãoComercial-CompartilhaIgual 3.0 Brasil License
 Implementando e utilizando o PL/SQL Profiler

Autor: Anderson Graf

Analista DBA Oracle na Teiko Soluçoes em TI.  Bacharel em Sistemas de Informação pela UNIFEBE -  certificado Oracle OCA 10G, OCP 10/11G, OCE Linux, OCS, OPNCS residente de Brusque/SC

Certificados:

oracle small Implementando e utilizando o PL/SQL Profiler oracle small Implementando e utilizando o PL/SQL Profiler oracle small Implementando e utilizando o PL/SQL Profiler oracle small Implementando e utilizando o PL/SQL Profiler oracle small Implementando e utilizando o PL/SQL Profiler