最近和优化团队的专家学到一个很有意义的内置包：dbms_profiler，专门用于分析Oracle存储过程中的各段代码的时间开销情况，从而快速找到性能瓶颈的步骤。

一、 sys创建dbms_profiler

conn /as sysdba
desc dbms_profiler    --先确认dbms_profiler包是否存在，如果不存在则通过下面的方式创建
@?/rdbms/admin/profload.sql

主要函数:

• start_profiler 启动对该程式监控
• stop_profiler 结束对该程式监控

二、 创建profiler用户和对象

conn / as sysdba;
CREATE USER profiler IDENTIFIED BY profiler;
grant connect,resource to profiler;
conn profiler/profiler;
@?/rdbms/admin/proftab.sql
GRANT SELECT ON plsql_profiler_runnumber TO PUBLIC;
GRANT SELECT,INSERT,UPDATE,DELETE ON plsql_profiler_data TO PUBLIC;
GRANT SELECT,INSERT,UPDATE,DELETE ON plsql_profiler_units TO PUBLIC;
GRANT SELECT,INSERT,UPDATE,DELETE ON plsql_profiler_runs TO PUBLIC;
-- 建同义词
CREATE PUBLIC SYNONYM plsql_profiler_runnumber FOR profiler.plsql_profiler_runnumber;
CREATE PUBLIC SYNONYM plsql_profiler_runs FOR profiler.plsql_profiler_runs;
CREATE PUBLIC SYNONYM plsql_profiler_units FOR profiler.plsql_profiler_units;
CREATE PUBLIC SYNONYM plsql_profiler_data FOR profiler.plsql_profiler_data;

备注：

• plsql_profiler_runs：prof运行信息
• plsql_profiler_units：prof每个单元信息
• plsql_profiler_data：prof每个单元的详细数据
• plsql_profiler_runnumber：用来生成prof唯一运行编号的序列

三、 使用dbms_profiler收集信息

假设要对下面这样的一个存储过程进行分析

CREATE OR REPLACE procedure sp_profiler_test1
as
begin
   for x in 1..10000
   loop
       insert into t_t1 values(x);
   end loop;
   commit;
end sp_profiler_test1;
/

收集该存储过程执行信息方法如下：

set serverout on;
 DECLARE
    v_run_number   integer;
    v_temp1        integer;
 BEGIN
    --启动profiler
    sys.DBMS_PROFILER.start_profiler (run_number => v_run_number);
    --显示当前跟踪的运行序号(后面查询要用)
    DBMS_OUTPUT.put_line ('run_number:' || v_run_number);
    --运行要跟踪的PLSQL
    sp_profiler_test1;   --前一步创建的测试样例存储过程
    --停止profiler
    sys.DBMS_PROFILER.stop_profiler;
 END;

四、 查询并分析结果

set linesize 1000
col text format a60
SELECT   d.line#,                      --代码行号
    s.text,                            --源代码
       d.total_time,                   --总共运行时间(单位10亿分之一秒，即10的-9次方。）
       d.total_occur,                  --总共运行次数
       d.min_time,                     --最小运行时间
       d.max_time                      --最大运行时间
    FROM   plsql_profiler_data d, sys.all_source s, plsql_profiler_units u
   WHERE       d.runid = 2             --运行号（上一步执行相关过程时显示号码）
    and u.unit_name = 'SP_PROFILER_TEST1'        --单元名，即被测试的存储过程名
       AND u.runid = d.runid
    AND d.unit_number = u.unit_number
    AND d.total_occur <> 0
    AND s.TYPE(+) = u.unit_type
    AND s.owner(+) = u.unit_owner
    AND s.name(+) = u.unit_name
    AND d.line# = NVL (s.line, d.line#)
   ORDER BY  d.total_time desc, u.unit_number, d.line#;

示例查询结果如下：

     LINE# TEXT                                   TOTAL_TIME TOTAL_OCCUR   MIN_TIME   MAX_TIME
---------- -------------------------------------- ---------- ----------- ---------- ----------
         6        insert into t_t1 values(x);      150147563       10000      13108    3831882
         4    for x in 1..10000                       613220       10001         26       7514
         8    commit;                                  75630           1      75630      75630
         9 end sp_profiler_test1;                       1683           1       1683       1683

Elapsed: 00:00:01.39

• LINE#：对应TEXT的语句在存储过程的第几行
• TOTAL_TIME：执行的总时间（单位ns）
• TOTAL_OCCUR：执行的次数
• MIN_TIME：最短单次的运行时间（单位ns）
• MAX_TIME：最长单次的运行时间（单位ns）

另附几个plsql相关sql

查询plsql执行时间占整个数据库执行时间比重

col db_time_secs format 999,999,999.99
col plsql_time_secs format 999,999,999.99
col pct_plsql_time format 99.99
col execs heading "Execs"
col text heading "Line text"
set lines 100
set pages 10000

set echo on
WITH plsql_times
       AS (SELECT SUM (CASE stat_name 
                            WHEN 'DB time' 
                            THEN value/1000000 END) AS db_time,
                  SUM(CASE stat_name
                           WHEN 'PL/SQL execution elapsed time'
                           THEN value / 1000000 END) AS plsql_time
             FROM v$sys_time_model
            WHERE stat_name IN ('DB time', 
                             'PL/SQL execution elapsed time'))
SELECT ROUND (db_time, 2) db_time_secs,
       ROUND (plsql_time, 2) plsql_time_secs,
       ROUND (plsql_time * 100 / db_time, 2) pct_plsql_time
  FROM plsql_times

通过v$sql获取所用时间详细数字，包含plsql执行时间、plsql占总sql执行时间比例、语句占数据库中所有plsql开销比例

set lines 100
set pages 1000
col sql_text format a30 heading "SQL Text"
col elapsed_ms format 9999999 heading "Total|time ms"
col plsql_ms format 99999999 heading "PLSQL|time ms"
col pct_plsql format 99.99 heading "Pct|PLSQL"
col pct_total_plsql format 99.99 heading "PCT of|Tot PLSQL"
set echo on 

SELECT sql_id,
       SUBSTR (sql_text, 1, 150) AS sql_text,
       ROUND (elapsed_time / 1000) AS elapsed_ms,
       ROUND (plsql_exec_time / 1000) plsql_ms,
       ROUND (plsql_exec_time * 100 / elapsed_time, 2) pct_plsql,
       ROUND (plsql_exec_time * 100 / SUM (plsql_exec_time) OVER (), 2)
          pct_total_plsql
  FROM v$sql
 WHERE plsql_exec_time > 0 AND elapsed_time > 0
ORDER BY plsql_exec_time DESC