使用DBMS_HPROF包收集PL/SQL性能信息

-----------------------------Cryking原创------------------------------
-----------------------转载请注明出处,谢谢!------------------------ 

 

 DBMS_HPROF包是oracle 11g出现的工具,是DBMS_PROFILER和DBMS_TRACE的综合.

这里简单演示如何使用DBMS_HPROF包来分析存储过程性能信息.

首先我们需要执行一个脚本来生成保存相关信息的表.

使用SYS用户执行$ORACLE_HOME/rdbms/admin/dbmshptab.sql

然后创建directory,

CREATE DIRECTORY LOG_FILE_DIR AS '/home/oracle';

先用SCOTT用户创建一个用于测试的存储过程insert_emp.

23:58:57 @ORCL> conn scott/tiger@orcl
Connected.
23:59:35 SCOTT@orcl> CREATE OR REPLACE PROCEDURE insert_emp(pempno number, pename varchar2) IS
23:59:45   2    stmt VARCHAR2(2000);
23:59:45   3  BEGIN
23:59:45   4    stmt := 'INSERT INTO emp_bak '
23:59:45   5    || '(EMPNO,ENAME) '
23:59:45   6    || 'SELECT :EMPNO,:ENAME'
23:59:45   7    || ' FROM DUAL';
23:59:45   8    dbms_output.put_line(stmt);
23:59:45   9    EXECUTE IMMEDIATE stmt
23:59:45  10      USING pempno, pename;
23:59:45  11  END insert_emp;
23:59:46  12  /

Procedure created.

Elapsed: 00:00:00.44


 

这里演示是在SYS用户下进行,如果要到指定用户执行,需要将DBMS_HPROF包的执行权限以及目录的读写权限赋予给该用户.

收集刚建立的存储过程的性能指标

00:06:11 SYS@orcl> DECLARE
00:10:42   2    v_runid         dbmshp_runs.runid%TYPE;
00:10:42   3    v_plshprof_dir  all_directories.directory_name%TYPE := 'LOG_FILE_DIR';
00:10:42   4    v_plshprof_file VARCHAR2(30) := 'insert_emp';
00:10:42   5  BEGIN
00:10:42   6    -- Start the profiling session
00:10:42   7    dbms_hprof.start_profiling(v_plshprof_dir, v_plshprof_file);
00:10:42   8    scott.insert_emp(9990,'Cryking!');
00:10:42   9    -- Stop the profiling session
00:10:42  10    dbms_hprof.stop_profiling;
00:10:42  11    -- Analyze the raw output and create the table data
00:10:42  12    v_runid := dbms_hprof.analyze(v_plshprof_dir, v_plshprof_file);
00:10:42  13    DBMS_OUTPUT.PUT_LINE('This Run: ' || to_char(v_runid));
00:10:42  14  END;
00:10:42  15  /
INSERT INTO emp_bak (EMPNO,ENAME) SELECT :EMPNO,:ENAME FROM DUAL
This Run: 1

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.26


 执行完后,会在对应目录生成一个insert_emp的文件,直接查看文件的话,内容很凌乱也很简短,如下:

P#! PL/SQL Timer Started
P#C PLSQL."SCOTT"."INSERT_EMP"::7."INSERT_EMP"#762ba075453b8b0d #1
P#X 1331
P#C PLSQL."SYS"."DBMS_OUTPUT"::11."PUT_LINE"#5892e4d73b579470 #109
P#X 4
P#C PLSQL."SYS"."DBMS_OUTPUT"::11."PUT"#5892e4d73b579470 #77
P#X 220
P#R
P#X 2
P#C PLSQL."SYS"."DBMS_OUTPUT"::11."NEW_LINE"#980980e97e42f8ec #117
P#X 4
P#R
P#X 3
P#R
P#X 83
P#C SQL."SCOTT"."INSERT_EMP"::7."__dyn_sql_exec_line9" #9
P#X 39858
P#R
P#X 14
P#R
P#C PLSQL."SYS"."DBMS_HPROF"::11."STOP_PROFILING"#980980e97e42f8ec #59
P#R
P#! PL/SQL Timer Stopped

 

这里需要使用工具plshprof对其进行分析,如下:

[oracle@oracleserver ~]$ plshprof insert_emp

PLSHPROF: Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production
[6 symbols processed]
[Report written to 'insert_emp.html']

[oracle@oracleserver ~]$ ls *.html
insert_emp_2c.html  insert_emp_fn.html  insert_emp_mf.html   insert_emp_nsf.html  insert_emp_tc.html  insert_emp_ts.html
insert_emp_2f.html  insert_emp.html     insert_emp_ms.html   insert_emp_nsp.html  insert_emp_td.html
insert_emp_2n.html  insert_emp_md.html  insert_emp_nsc.html  insert_emp_pc.html   insert_emp_tf.html

然后我们再查看文件insert_emp.html的内容,如下:

<HTML lang="en">
<HEAD>
<TITLE>PL/SQL Elapsed Time (microsecs) Analysis for 'insert_emp'</TITLE>
</HEAD>
<BODY>

<H1>PL/SQL Elapsed Time (microsecs) Analysis</H1>
<H3>41519 microsecs (elapsed time) & 6 function calls</H3>
<H3>The PL/SQL Hierarchical Profiler produces a collection of reports that
present information derived from the profiler's output log in a variety
of formats.  The following reports have been found to be the most generally
useful as starting points for browsing:</H3>
<UL>
<LI> <A HREF = insert_emp_ts.html>
     Function Elapsed Time (microsecs) Data sorted by Total Subtree Elapsed Time (microsecs)
     </A> </LI>
<LI> <A HREF = insert_emp_tf.html>
     Function Elapsed Time (microsecs) Data sorted by Total Function Elapsed Time (microsecs)
     </A> </LI>
</UL>
<H3>In addition, the following reports are also available:</H3>
<UL>
<LI> <A HREF = insert_emp_fn.html>
     Function Elapsed Time (microsecs) Data sorted by Function Name
     </A> </LI>
<LI> <A HREF = insert_emp_td.html>
     Function Elapsed Time (microsecs) Data sorted by Total Descendants Elapsed Time (microsecs)
     </A> </LI>
<LI> <A HREF = insert_emp_tc.html>
     Function Elapsed Time (microsecs) Data sorted by Total Function Call Count
     </A> </LI>
<LI> <A HREF = insert_emp_ms.html>
     Function Elapsed Time (microsecs) Data sorted by Mean Subtree Elapsed Time (microsecs)
     </A> </LI>
<LI> <A HREF = insert_emp_mf.html>
     Function Elapsed Time (microsecs) Data sorted by Mean Function Elapsed Time (microsecs)
     </A> </LI>
<LI> <A HREF = insert_emp_md.html>
     Function Elapsed Time (microsecs) Data sorted by Mean Descendants Elapsed Time (microsecs)
     </A> </LI>
<LI> <A HREF = insert_emp_2f.html>
     Module Elapsed Time (microsecs) Data sorted by Total Function Elapsed Time (microsecs)
.......


 通过浏览器查看,我们可以点击各个链接,查看,如点击Function Elapsed Time (microsecs) Data sorted by Total Subtree Elapsed Time (microsecs)后,结果如下图:

从图可知,函数最耗时的语句为SCOTT.INSERT_EMO._dyn_sql_exec_line9(即为执行动态sql那一行),耗时39858微秒,整个函数共耗时41519微秒.

还可以点击Function Name列查看更详细的内容.

PS:其实生成的HTML大部分信息都是来自dbmshp_function_info和dbmshp_parent_child_info表.

 

评论 1
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值