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 “?” apos 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.
segundo script a ser executado:
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 varias outras 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 00/00/00
2 3 ANONYMOUS BLOCK 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 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.
