ITPub博客

首页 > 数据库 > Oracle > 使用dbms_profiler来观察每一行PLSQL程序的执行时间

使用dbms_profiler来观察每一行PLSQL程序的执行时间

原创 Oracle 作者:hooca 时间:2014-10-25 21:22:20 0 删除 编辑
使用dbms_profiler来观察每一行PLSQL程序的执行时间
有时候我们在执行一段比较长的plsql程序的时候,发现执行过程比较慢,但又不知道是哪部分出现了性能问题,这时候应该如何快速找到最耗费时间的部分呢?当然有很多方法,但这里推荐一种方法,可以使用dbms_profiler包来观察每一行代码的执行次数和时间。
一、操作步骤
1. 登录到SYS用户,检查dbms_profiler包有没有安装。没有的话运行$ORACLE_HOME/rdbms/admin/profload.sql来创建该包。
2. 将该包的执行权限赋予待调试的用户。
3. 登录到调试用户,运行$ORACLE_HOME/rdbms/admin/proftab.sql创建相关表。
4. 在待优化的PL/SQL程序前后加上运行dbms_profiler包的代码,如下:
BEGIN
  DBMS_PROFILER.START_PROFILER('any comment');
  ...'your pl/sql code'
  DBMS_PROFILER.STOP_PROFILER;
  ...
END;
5. 运行该PL/SQL程序,然后检查PLSQL_PROFILER_DATA表内容,可以从中看到每一行代码的执行次数,每行代码总共的执行时间。
二、具体的例子:
SQL> conn / as sysdba;
Connected.
1.检查是否安装了dbms_profiler包
SQL> desc dbms_profiler;
ERROR:
ORA-04043: object dbms_profiler does not exist
--如果没有安装的话,执行下面的语句安装
SQL> @/disk_dev/oracle/product/9.2.0/rdbms/admin/profload.sql;
Package created.
Grant succeeded.
Synonym created.
Library created.
Package body created.
Testing for correct installation
SYS.DBMS_PROFILER successfully loaded.
PL/SQL procedure successfully completed.
2.把dbms_profiler的执行权限赋于oauser
SQL> grant execute on dbms_profiler to oauser;
Grant succeeded.
3.使用oauser登录,执行proftab.sql,此文件实际是创建plsql_profiler_data、plsql_profiler_units、plsql_profiler_runs三个表,具体proftab.sql的内容如下:
proftab.sql:
drop table plsql_profiler_data cascade constraints;
drop table plsql_profiler_units cascade constraints;
drop table plsql_profiler_runs cascade constraints;
drop sequence plsql_profiler_runnumber;
create table plsql_profiler_runs
(
  runid           number primary key,  -- unique run identifier,
                                       -- from plsql_profiler_runnumber
  related_run     number,              -- runid of related run (for client/
                                       --     server correlation)
  run_owner       varchar2(32),        -- user who started run
  run_date        date,                -- start time of run
  run_comment     varchar2(2047),      -- user provided comment for this run
  run_total_time  number,              -- elapsed time for this run
  run_system_info varchar2(2047),      -- currently unused
  run_comment1    varchar2(2047),      -- additional comment
  spare1          varchar2(256)        -- unused
);
 
comment on table plsql_profiler_runs is
        'Run-specific information for the PL/SQL profiler';
create table plsql_profiler_units
(
  runid              number references plsql_profiler_runs,
  unit_number        number,           -- internally generated library unit #
  unit_type          varchar2(32),     -- library unit type
  unit_owner         varchar2(32),     -- library unit owner name
  unit_name          varchar2(32),     -- library unit name
  -- timestamp on library unit, can be used to detect changes to
  -- unit between runs
  unit_timestamp     date,
  total_time         number DEFAULT 0 NOT NULL,
  spare1             number,           -- unused
  spare2             number,           -- unused
  -- 
  primary key (runid, unit_number)
);
comment on table plsql_profiler_units is
        'Information about each library unit in a run';
create table plsql_profiler_data
(
  runid           number,           -- unique (generated) run identifier
  unit_number     number,           -- internally generated library unit #
  line#           number not null,  -- line number in unit
  total_occur     number,           -- number of times line was executed
  total_time      number,           -- total time spent executing line
  min_time        number,           -- minimum execution time for this line
  max_time        number,           -- maximum execution time for this line
  spare1          number,           -- unused
  spare2          number,           -- unused
  spare3          number,           -- unused
  spare4          number,           -- unused
  --
  primary key (runid, unit_number, line#),
  foreign key (runid, unit_number) references plsql_profiler_units
);
comment on table plsql_profiler_data is
        'Accumulated data from all profiler runs';
create sequence plsql_profiler_runnumber start with 1 nocache;
SQL> conn oauser/oauser;
Connected.
SQL> @/disk_dev/oracle/product/9.2.0/rdbms/admin/proftab.sql;
4.创建一个测试的过程,在代码中加入dbms_profiler代码,如下:
create or replace procedure p_dbms_profiler_test
 is
 i number :=1 ;
 v_str varchar2(4000);
begin
  dbms_profiler.start_profiler('测试一下');
  dbms_output.put_line(i);
  for i in 1..100 loop
   exit when length(v_str)>100;
    v_str := v_str||i;
  end loop;
  dbms_output.put_line(v_str);
  dbms_profiler.stop_profiler;
end p_dbms_profiler_test;
 
SQL> exec p_dbms_profiler_test;
PL/SQL procedure successfully completed
SQL> exec p_dbms_profiler_test;
PL/SQL procedure successfully completed
SQL> exec p_dbms_profiler_test;
PL/SQL procedure successfully completed
执行一次p_dbms_profiler_test过程,就会分别在plsql_profiler_units和plsql_profiler_runs插入一条信息,在plsql_profiler_data插入具体的过程执行数据。
5.查看结果
通过下面的SQL语句我们可以知道每一行代码的执行次数,时间等等。
SQL> select t1.line#,t3.text,t1.total_occur,t1.total_time,min_time, max_time
  2  from plsql_profiler_data t1,plsql_profiler_units t2,user_source t3
  3  where t1.runid = t2.runid
  4     and t2.unit_name='P_DBMS_PROFILER_TEST'
  5     and t2.unit_name = t3.name
  6     and t1.line#=t3.line
  7     and t1.runid=3
  8  order by t1.line#
  9  /
 
LINE# TEXT                                        TOTAL_OCCUR TOTAL_TIME   MIN_TIME   MAX_TIME
---------- -------------------------------------------------------------------------------- --
    3  i number :=1 ;                                       0          0          0          0
    6   dbms_profiler.start_profiler('测试一下');           0          0          0          0
    7   dbms_output.put_line(i);                            1      17000      17000      17000
    8   for i in 1..100 loop                               56     222000       2000       6000
    9    exit when length(v_str)>100;                      56     232000       3000       7000
   10     v_str := v_str||i;                               55     254000       3000      16000
   12   dbms_output.put_line(v_str);                        1       5000       5000       5000
   13   dbms_profiler.stop_profiler;                        1       5000       5000       5000
   14 end p_dbms_profiler_test;                             0          0          0         0
9 rows selected

来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/22621861/viewspace-1309740/,如需转载,请注明出处,否则将追究法律责任。

上一篇: 表收缩技术
请登录后发表评论 登录
全部评论

注册时间:2009-09-29

  • 博文量
    215
  • 访问量
    403004