Oracle利用 DBMS_PROFILER 包来分析PL/SQL瓶颈

在 Oracle 10g 版本之前，默认情况下不会安装 DBMS_PROFILER 包，此次演示版本为11.2.0.4.0，默认已经安装。

安装 DBMS_PROFILER 包方式如下：

sqlplus / as sysdba
desc dbms_profiler    --不存在则通过下面的方式创建
@?/rdbms/admin/profload.sql

另外，DBMS_PROFILER 包收集的分析信息存储在多个表中，而这些表默认情况下不会创建，需要在使用 DBMS_PROFIER 包之前在所有数据库版本中显式创建。

方法是运行位于 $ORACLE_HOME/rdbms/admin 文件夹中的脚本“proftab.sql”。这些表可以在普通用户或 SYS 用户中创建，如果在 SYS 中创建，则需要向想要使用 DBMS_PROFILER 包的用户授予适当的权限。

运行“proftab.sql”创建以下对象：

PLSQL_PROFILER_RUNS - PL/SQL 探查器的运行特定信息。
PLSQL_PROFILER_UNITS - 有关运行中每个库单元的信息。
PLSQL_PROFILER_DATA - 所有分析器运行的累积数据。
序列 PLSQL_PROFILER_RUNNUMBER

这里使用 SYS 用户创建并授权：

sqlplus / as sysdba
@?/rdbms/admin/proftab.sql

GRANT SELECT ON plsql_profiler_runnumber TO PUBLIC;
GRANT SELECT,INSERT,UPDATE,DELETE ON sys.plsql_profiler_data  TO PUBLIC;
GRANT SELECT,INSERT,UPDATE,DELETE ON sys.plsql_profiler_units TO PUBLIC;
GRANT SELECT,INSERT,UPDATE,DELETE ON sys.plsql_profiler_runs  TO PUBLIC;

CREATE PUBLIC SYNONYM sys.plsql_profiler_runnumber FOR plsql_profiler_runnumber;
CREATE PUBLIC SYNONYM sys.plsql_profiler_runs      FOR plsql_profiler_runs;
CREATE PUBLIC SYNONYM sys.plsql_profiler_units     FOR plsql_profiler_units;
CREATE PUBLIC SYNONYM sys.plsql_profiler_data      FOR plsql_profiler_data;

https://www.cnblogs.com/PiscesCanon/p/17684336.html

这样所有的普通用户都有权限操作以上涉及的4个对象。

接下来使用普通用户ZKM进行测试，创建测试表和存储过程如下：

CREATE TABLE zkm (id int);

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

开始测试：

1.
SET SERVEROUTPUT ON
DECLARE
  v_run_id    PLS_INTEGER;
  v_ret_value PLS_INTEGER;
BEGIN
  v_ret_value := DBMS_PROFILER.START_PROFILER('TEST PROFILER','SAMPLE PROFILER',v_run_id);
  DBMS_OUTPUT.PUT_LINE ('The run_number is : ' || v_run_id);
EXCEPTION WHEN OTHERS THEN
  DBMS_OUTPUT.PUT_LINE('Error while starting the profiler :' || SQLERRM);
END;
/

2.
EXEC proc_insert_zkm;     --你需要调试的SQL、存储过程，匿名块等

3.
BEGIN
  DBMS_PROFILER.STOP_PROFILER;
EXCEPTION WHEN OTHERS THEN
  DBMS_OUTPUT.PUT_LINE('Error while stopping the profiler :' || SQLERRM);
END;
/

方便复制

同个会话执行：

---step 1
10:54:50 ZKM@zkmdb(26)> SET SERVEROUTPUT ON
10:54:57 ZKM@zkmdb(26)> DECLARE
10:54:57   2    v_run_id    PLS_INTEGER;
10:54:57   3    v_ret_value PLS_INTEGER;
10:54:57   4  BEGIN
10:54:57   5    v_ret_value := DBMS_PROFILER.START_PROFILER('TEST PROFILER','SAMPLE PROFILER',v_run_id);
10:54:57   6    DBMS_OUTPUT.PUT_LINE ('The run_number is : ' || v_run_id);
10:54:57   7  EXCEPTION WHEN OTHERS THEN
10:54:57   8    DBMS_OUTPUT.PUT_LINE('Error while starting the profiler :' || SQLERRM);
10:54:57   9  END;
10:54:57  10  /
The run_number is : 4

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.00

---step 2
10:55:00 ZKM@zkmdb(26)> EXEC proc_insert_zkm;

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.96

---step 3
10:55:11 ZKM@zkmdb(26)> BEGIN
10:55:14   2    DBMS_PROFILER.STOP_PROFILER;
10:55:14   3  EXCEPTION WHEN OTHERS THEN
10:55:14   4    DBMS_OUTPUT.PUT_LINE('Error while stopping the profiler :' || SQLERRM);
10:55:14   5  END;
10:55:14   6  /

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.01

可以查询视图PLSQL_PROFILER_RUNS来查看执行过的DBMS_PROFILER来调试的信息：

10:59:53 SYS@zkmdb(503)> COL RUN_COMMENT FOR A25
11:00:08 SYS@zkmdb(503)> SELECT RUNID, RUN_DATE, RUN_COMMENT FROM PLSQL_PROFILER_RUNS;

     RUNID RUN_DATE            RUN_COMMENT
---------- ------------------- -------------------------
         1 2023-09-07 10:37:38 TEST PROFILER
         2 2023-09-07 10:38:15 TEST PROFILER
         3 2023-09-07 10:46:52 TEST PROFILER
         4 2023-09-07 10:47:59 TEST PROFILER
         5 2023-09-07 10:54:20 TEST PROFILER

Elapsed: 00:00:00.00

通过上边step 1步骤获得的run_number为4，结合一下脚本可以查询到我们需要的信息：

COLUMN UNIT_NAME FORMAT A35
COLUMN OCCURRED  FORMAT 999999
COLUMN LINE      FORMAT 9999
COLUMN TOT_TIME  FORMAT 999.999999
COLUMN TEXT      FORMAT A46
SELECT P.UNIT_NAME, P.OCCURRED, P.TOT_TIME, P.MIN_TIME, P.MAX_TIME, P.LINE# LINE, SUBSTR(S.TEXT, 1,75) TEXT
FROM (SELECT U.UNIT_NAME, D.TOTAL_OCCUR OCCURRED, (D.TOTAL_TIME/1E9) TOT_TIME, D.MIN_TIME/1E9 MIN_TIME, D.MAX_TIME/1E9 MAX_TIME,
D.LINE# FROM PLSQL_PROFILER_UNITS U, PLSQL_PROFILER_DATA D
WHERE D.RUNID=U.RUNID AND D.UNIT_NUMBER = U.UNIT_NUMBER AND D.TOTAL_OCCUR >0
AND U.RUNID= 4) P,USER_SOURCE S
WHERE P.UNIT_NAME = S.NAME(+) AND P.LINE# = S.LINE (+)
ORDER BY P.LINE#;

方便复制

10:59:27 ZKM@zkmdb(26)> COLUMN UNIT_NAME FORMAT A35
11:03:00 ZKM@zkmdb(26)> COLUMN OCCURRED  FORMAT 999999
11:03:00 ZKM@zkmdb(26)> COLUMN LINE      FORMAT 9999
11:03:00 ZKM@zkmdb(26)> COLUMN TOT_TIME  FORMAT 999.999999
11:03:00 ZKM@zkmdb(26)> COLUMN TEXT      FORMAT A46
11:03:01 ZKM@zkmdb(26)> SELECT P.UNIT_NAME, P.OCCURRED, P.TOT_TIME, P.MIN_TIME, P.MAX_TIME, P.LINE# LINE, SUBSTR(S.TEXT, 1,75) TEXT
11:03:01   2  FROM (SELECT U.UNIT_NAME, D.TOTAL_OCCUR OCCURRED, (D.TOTAL_TIME/1E9) TOT_TIME, D.MIN_TIME/1E9 MIN_TIME, D.MAX_TIME/1E9 MAX_TIME,
11:03:01   3  D.LINE# FROM PLSQL_PROFILER_UNITS U, PLSQL_PROFILER_DATA D
11:03:01   4  WHERE D.RUNID=U.RUNID AND D.UNIT_NUMBER = U.UNIT_NUMBER AND D.TOTAL_OCCUR >0
11:03:01   5  AND U.RUNID= 4) P,USER_SOURCE S
11:03:01   6  WHERE P.UNIT_NAME = S.NAME(+) AND P.LINE# = S.LINE (+)
11:03:01   7  ORDER BY P.LINE#;

UNIT_NAME                           OCCURRED    TOT_TIME   MIN_TIME   MAX_TIME  LINE TEXT
----------------------------------- -------- ----------- ---------- ---------- ----- ----------------------------------------------
<anonymous>                                3     .000028    .000001    .000024     1
<anonymous>                                2     .000086    .000003    .000038     1
<anonymous>                                2     .000116    .000004     .00004     1
<anonymous>                                2     .000065          0    .000063     1
<anonymous>                                2     .000094    .000004    .000041     1
<anonymous>                                1     .000004    .000004    .000004     1
<anonymous>                                2     .000063    .000001    .000062     2
PROC_INSERT_ZKM                        10001     .001925          0    .000016     4    for x in 1..10000
<anonymous>                                1     .000037    .000037    .000037     5
<anonymous>                                1     .000043    .000043    .000043     6
<anonymous>                                1     .000041    .000041    .000041     6
PROC_INSERT_ZKM                        10000     .571903    .000049 .001052005     6        insert into zkm values(x);
PROC_INSERT_ZKM                        10000     .383340    .000033 .000887004     7       commit;
PROC_INSERT_ZKM                            1     .000002    .000002    .000002     9 end proc_insert_zkm;
<anonymous>                                1     .000001    .000001    .000001     9
<anonymous>                                1     .000001    .000001    .000001    11

16 rows selected.

Elapsed: 00:00:00.06