划线反馈

DBMS_PROFILER 存储过程调优工具

更新时间：2026-05-29 08:46

适用版本：V4.2.x、V4.3.x内容类型：TechNote

OceanBase 数据库 V4.2.3 及之后版本可以通过 DBMS_PROFILER 系统来进行存储过程内慢 SQL 的行级耗时性能定位。

OceanBase PL 执行可能存在潜在的性能问题，通常我们需要通过技术手段定位 PL 中的性能原因，再通过改写等手段规避或者优化。但是，在 OceanBase 数据库 V4.2.3 之前的版本中，定位 PL 性能问题的手段相对有限，大部分场景只能通过 GV$OB_SQL_AUDIT 视图确认 PL 和其内部 SQL 的执行时间差异来分析性能问题，对语法块（WHILE、FOR 等）和语句级别的执行时间缺乏有效诊断手段。

在某些业务跑批等场景下，通常是在循环语句中大量反复执行相同的 SQL 语句来完成业务统计或者更新。若触发 SQL AUDIT 视图淘汰机制，则导致无法有效记录完整的 PL 和 SQL 语句的执行时间，难以准确定位和解决性能瓶颈问题。因此，OceanBase 数据库引入了新的性能剖析机制（dbms_profiler），记录更细粒度的执行时间，准确收集每一行的执行时间，从而有效诊断 PL 运行时的性能问题。

详细说明

性能测试 PL

delimiter $$
CREATE OR REPLACE PROCEDURE do_something_3 (p_times  IN  NUMBER) AS
  l_dummy  NUMBER;
BEGIN
  FOR i IN 1 .. p_times LOOP
    SELECT l_dummy + 1
    INTO   l_dummy
    FROM   dual;
  END LOOP;
END;
$$

delimiter $$
CREATE OR REPLACE PROCEDURE do_something_2 (p_times  IN  NUMBER) AS
BEGIN
  FOR i IN 1 .. p_times LOOP
    do_something_3(p_times => p_times);
  END LOOP;
END;
$$


delimiter $$
CREATE OR REPLACE PROCEDURE do_something_1 (p_times  IN  NUMBER) AS
BEGIN
  FOR i IN 1 .. p_times LOOP
    do_something_2(p_times => p_times);
  END LOOP;
END;
$$

delimiter ;

使用方式

启动剖析器

call DBMS_PROFILER.start_profiler(run_comment => 'zxtest_do_something: ' || SYSDATE);

关闭剖析器

call DBMS_PROFILER.stop_profiler();

查询每次启动的 runid 和时间、注释等信息

select * from plsql_profiler_runs;

查询每次执行中每个 PL 单元的信息

--runid为当前启动剖析器是分配的id。
select * from plsql_profiler_units where runid=17;

查询每次执行每行的耗时

select * from plsql_profiler_data where runid=17;

信息汇总

SELECT u.runid,
       u.unit_number,
       u.unit_type,
       u.unit_owner,
       u.unit_name,
       d.line#,
       d.total_occur,
       d.total_time,
       d.min_time,
       d.max_time
FROM   plsql_profiler_units u
       JOIN plsql_profiler_data d ON u.runid = d.runid AND u.unit_number = d.unit_number
WHERE  u.runid = 17 and u.unit_name in ('DO_SOMETHING_1','DO_SOMETHING_2','DO_SOMETHING_3')
ORDER BY u.unit_number, d.line#;

源码查看

SELECT u.runid,
       u.unit_number,
       u.unit_type,
       s.type,
       u.unit_owner,
       u.unit_name,
       d.line#,
       s.text,
       d.total_occur,
       d.total_time,
       d.min_time,
       d.max_time
FROM   plsql_profiler_units u
       JOIN plsql_profiler_data d ON u.runid = d.runid AND u.unit_number = d.unit_number
       JOIN all_source s ON u.unit_owner=s.owner AND u.unit_name=s.name AND d.line#=s.line
WHERE  u.runid = 1 and u.unit_name in ('DO_SOMETHING_1','DO_SOMETHING_2','DO_SOMETHING_3')
ORDER BY u.unit_number, d.line#;

测试结果

obclient(SETTLEADMIN@oracle)[SETTLEADMIN]> call DBMS_PROFILER.start_profiler(run_comment => 'zxtest_do_something: ' || SYSDATE);
Query OK, 0 rows affected (0.022 sec)

obclient(SETTLEADMIN@oracle)[SETTLEADMIN]> call do_something_1(p_times => 10);
Query OK, 0 rows affected (0.199 sec)

obclient(SETTLEADMIN@oracle)[SETTLEADMIN]> call DBMS_PROFILER.stop_profiler();
Query OK, 0 rows affected (0.147 sec)

--每次启动的 runid 和时间、注释等信息
--最后一行为测试结果
obclient(SETTLEADMIN@oracle)[SETTLEADMIN]> select * from plsql_profiler_runs;
+-------+-------------+-------------+-----------+--------------------------------+----------------+-----------------+--------------+--------+
| RUNID | RELATED_RUN | RUN_OWNER   | RUN_DATE  | RUN_COMMENT                    | RUN_TOTAL_TIME | RUN_SYSTEM_INFO | RUN_COMMENT1 | SPARE1 |
+-------+-------------+-------------+-----------+--------------------------------+----------------+-----------------+--------------+--------+
|     1 |        NULL | SETTLEADMIN | 05-DEC-24 | do_something: 05-DEC-24        |              0 | NULL            | NULL         | NULL   |
|     2 |        NULL | SETTLEADMIN | 05-DEC-24 | do_something: 05-DEC-24        |              0 | NULL            | NULL         | NULL   |
|     3 |        NULL | SETTLEADMIN | 05-DEC-24 | do_something: 05-DEC-24        |    49000000000 | NULL            | NULL         | NULL   |
|     4 |        NULL | SETTLEADMIN | 05-DEC-24 | do_something: 05-DEC-24        |              0 | NULL            | NULL         | NULL   |
|     5 |        NULL | SETTLEADMIN | 05-DEC-24 | do_something: 05-DEC-24        |    15000000000 | NULL            | NULL         | NULL   |
|     6 |        NULL | SETTLEADMIN | 05-DEC-24 | do_something: 05-DEC-24        |              0 | NULL            | NULL         | NULL   |
|     7 |        NULL | SETTLEADMIN | 05-DEC-24 | do_something: 05-DEC-24        |              0 | NULL            | NULL         | NULL   |
|     8 |        NULL | SETTLEADMIN | 05-DEC-24 | do_something: 05-DEC-24        |              0 | NULL            | NULL         | NULL   |
|     9 |        NULL | SETTLEADMIN | 05-DEC-24 | do_something: 05-DEC-24        |              0 | NULL            | NULL         | NULL   |
|    10 |        NULL | SETTLEADMIN | 05-DEC-24 | do_something: 05-DEC-24        |    10000000000 | NULL            | NULL         | NULL   |
|    11 |        NULL | SETTLEADMIN | 05-DEC-24 | do_something: 05-DEC-24        |              0 | NULL            | NULL         | NULL   |
|    12 |        NULL | SETTLEADMIN | 05-DEC-24 | do_something: 05-DEC-24        |              0 | NULL            | NULL         | NULL   |
|    13 |        NULL | SETTLEADMIN | 05-DEC-24 | do_something: 05-DEC-24        |              0 | NULL            | NULL         | NULL   |
|    14 |        NULL | SETTLEADMIN | 05-DEC-24 | do_something: 05-DEC-24        |              0 | NULL            | NULL         | NULL   |
|    15 |        NULL | SETTLEADMIN | 05-DEC-24 | do_something: 05-DEC-24        |              0 | NULL            | NULL         | NULL   |
|    16 |        NULL | SETTLEADMIN | 09-DEC-24 | do_something: 09-DEC-24        |     8000000000 | NULL            | NULL         | NULL   |
|    17 |        NULL | SETTLEADMIN | 09-DEC-24 | zxtest_do_something: 09-DEC-24 |     7000000000 | NULL            | NULL         | NULL   |
+-------+-------------+-------------+-----------+--------------------------------+----------------+-----------------+--------------+--------+

--每次执行中每个 PL 单元的信息
obclient(SETTLEADMIN@oracle)[SETTLEADMIN]> select * from plsql_profiler_units where runid=17;
+-------+-------------+--------------+-------------+----------------+----------------+------------+--------+--------+
| RUNID | UNIT_NUMBER | UNIT_TYPE    | UNIT_OWNER  | UNIT_NAME      | UNIT_TIMESTAMP | TOTAL_TIME | SPARE1 | SPARE2 |
+-------+-------------+--------------+-------------+----------------+----------------+------------+--------+--------+
|    17 |      310867 | PACKAGE BODY | SYS         | DBMS_PROFILER  | 02-DEC-24      |          0 |   NULL |   NULL |
|    17 |      500359 | PROCEDURE    | SETTLEADMIN | DO_SOMETHING_3 | 09-DEC-24      |          0 |   NULL |   NULL |
|    17 |      500360 | PROCEDURE    | SETTLEADMIN | DO_SOMETHING_2 | 09-DEC-24      |          0 |   NULL |   NULL |
|    17 |      500361 | PROCEDURE    | SETTLEADMIN | DO_SOMETHING_1 | 09-DEC-24      |          0 |   NULL |   NULL |
+-------+-------------+--------------+-------------+----------------+----------------+------------+--------+--------+


--每次执行每行的耗时
obclient(SETTLEADMIN@oracle)[SETTLEADMIN]> select * from plsql_profiler_data where runid=17;
+-------+-------------+-------+-------------+------------+----------+----------+--------+--------+--------+--------+
| RUNID | UNIT_NUMBER | LINE# | TOTAL_OCCUR | TOTAL_TIME | MIN_TIME | MAX_TIME | SPARE1 | SPARE2 | SPARE3 | SPARE4 |
+-------+-------------+-------+-------------+------------+----------+----------+--------+--------+--------+--------+
|    17 |      310867 |     1 |           2 |      10371 |     2169 |     8202 |   NULL |   NULL |   NULL |   NULL |
|    17 |      310867 |    11 |           2 |        997 |      359 |      638 |   NULL |   NULL |   NULL |   NULL |
|    17 |      310867 |    14 |           2 |      82153 |    23109 |    59044 |   NULL |   NULL |   NULL |   NULL |
|    17 |      310867 |    80 |           1 |       2765 |     2765 |     2765 |   NULL |   NULL |   NULL |   NULL |
|    17 |      310867 |   122 |           1 |       4102 |     4102 |     4102 |   NULL |   NULL |   NULL |   NULL |
|    17 |      310867 |   123 |           1 |       5898 |     5898 |     5898 |   NULL |   NULL |   NULL |   NULL |
|    17 |      500359 |     1 |         100 |     356062 |     2312 |    25303 |   NULL |   NULL |   NULL |   NULL |
|    17 |      500359 |     2 |         100 |     121283 |      700 |     9009 |   NULL |   NULL |   NULL |   NULL |
|    17 |      500359 |     4 |        1000 |     268831 |      193 |    11091 |   NULL |   NULL |   NULL |   NULL |
|    17 |      500359 |     5 |        1000 |   60829022 |    22812 |  4636191 |   NULL |   NULL |   NULL |   NULL |
|    17 |      500360 |     1 |          10 |      46980 |     3380 |     8429 |   NULL |   NULL |   NULL |   NULL |
|    17 |      500360 |     3 |         100 |      27091 |      204 |      451 |   NULL |   NULL |   NULL |   NULL |
|    17 |      500360 |     4 |         100 |    3006870 |    19294 |   186324 |   NULL |   NULL |   NULL |   NULL |
|    17 |      500361 |     1 |           1 |      31967 |    31967 |    31967 |   NULL |   NULL |   NULL |   NULL |
|    17 |      500361 |     3 |          10 |       3191 |      256 |      628 |   NULL |   NULL |   NULL |   NULL |
|    17 |      500361 |     4 |          10 |     381646 |    28464 |    61232 |   NULL |   NULL |   NULL |   NULL |
+-------+-------------+-------+-------------+------------+----------+----------+--------+--------+--------+--------+

-- 对应到存储过程
obclient(SETTLEADMIN@oracle)[SETTLEADMIN]> SELECT u.runid,
            u.unit_number,
            u.unit_type,
            u.unit_owner,
            u.unit_name,
            d.line#,
            d.total_occur,
            d.total_time,
            d.min_time,
            d.max_time
     FROM   plsql_profiler_units u
            JOIN plsql_profiler_data d ON u.runid = d.runid AND u.unit_number = d.unit_number
     WHERE  u.runid = 17 and u.unit_name in ('DO_SOMETHING_1','DO_SOMETHING_2','DO_SOMETHING_3')
     ORDER BY u.unit_number, d.line#;
+-------+-------------+-----------+-------------+----------------+-------+-------------+------------+----------+----------+
| RUNID | UNIT_NUMBER | UNIT_TYPE | UNIT_OWNER  | UNIT_NAME      | LINE# | TOTAL_OCCUR | TOTAL_TIME | MIN_TIME | MAX_TIME |
+-------+-------------+-----------+-------------+----------------+-------+-------------+------------+----------+----------+
|    17 |      500359 | PROCEDURE | SETTLEADMIN | DO_SOMETHING_3 |     1 |         100 |     356062 |     2312 |    25303 |
|    17 |      500359 | PROCEDURE | SETTLEADMIN | DO_SOMETHING_3 |     2 |         100 |     121283 |      700 |     9009 |
|    17 |      500359 | PROCEDURE | SETTLEADMIN | DO_SOMETHING_3 |     4 |        1000 |     268831 |      193 |    11091 |
|    17 |      500359 | PROCEDURE | SETTLEADMIN | DO_SOMETHING_3 |     5 |        1000 |   60829022 |    22812 |  4636191 |
|    17 |      500360 | PROCEDURE | SETTLEADMIN | DO_SOMETHING_2 |     1 |          10 |      46980 |     3380 |     8429 |
|    17 |      500360 | PROCEDURE | SETTLEADMIN | DO_SOMETHING_2 |     3 |         100 |      27091 |      204 |      451 |
|    17 |      500360 | PROCEDURE | SETTLEADMIN | DO_SOMETHING_2 |     4 |         100 |    3006870 |    19294 |   186324 |
|    17 |      500361 | PROCEDURE | SETTLEADMIN | DO_SOMETHING_1 |     1 |           1 |      31967 |    31967 |    31967 |
|    17 |      500361 | PROCEDURE | SETTLEADMIN | DO_SOMETHING_1 |     3 |          10 |       3191 |      256 |      628 |
|    17 |      500361 | PROCEDURE | SETTLEADMIN | DO_SOMETHING_1 |     4 |          10 |     381646 |    28464 |    61232 |
+-------+-------------+-----------+-------------+----------------+-------+-------------+------------+----------+----------+
10 rows in set (0.007 sec)

和 source 表 join 可以查看 PL 源码
obclient(SETTLEADMIN@oracle)[SETTLEADMIN]> SELECT u.runid,
            u.unit_number,
            u.unit_type,
            s.type,
            u.unit_owner,
            u.unit_name,
            d.line#,
            s.text,
            d.total_occur,
            d.total_time,
            d.min_time,
            d.max_time
     FROM   plsql_profiler_units u
            JOIN plsql_profiler_data d ON u.runid = d.runid AND u.unit_number = d.unit_number
            JOIN all_source s ON u.unit_owner=s.owner AND u.unit_name=s.name AND d.line#=s.line
     WHERE  u.runid = 17 and u.unit_name in ('DO_SOMETHING_1','DO_SOMETHING_2','DO_SOMETHING_3')
     ORDER BY u.unit_number, d.line#;
+-------+-------------+-----------+-----------+-------------+----------------+-------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------+------------+----------+----------+
| RUNID | UNIT_NUMBER | UNIT_TYPE | TYPE      | UNIT_OWNER  | UNIT_NAME      | LINE# | TEXT                                                                                                                                                                                | TOTAL_OCCUR | TOTAL_TIME | MIN_TIME | MAX_TIME |
+-------+-------------+-----------+-----------+-------------+----------------+-------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------+------------+----------+----------+
|    17 |      500359 | PROCEDURE | PROCEDURE | SETTLEADMIN | DO_SOMETHING_3 |     1 | PROCEDURE do_something_3 (p_times  IN  NUMBER) AS
  l_dummy  NUMBER;
BEGIN
  FOR i IN 1 .. p_times LOOP
    SELECT l_dummy + 1
    INTO   l_dummy
    FROM   dual;
  END LOOP;
END; |         100 |     356062 |     2312 |    25303 |
|    17 |      500360 | PROCEDURE | PROCEDURE | SETTLEADMIN | DO_SOMETHING_2 |     1 | PROCEDURE do_something_2 (p_times  IN  NUMBER) AS
BEGIN
  FOR i IN 1 .. p_times LOOP
    do_something_3(p_times => p_times);
  END LOOP;
END;                                       |          10 |      46980 |     3380 |     8429 |
|    17 |      500361 | PROCEDURE | PROCEDURE | SETTLEADMIN | DO_SOMETHING_1 |     1 | PROCEDURE do_something_1 (p_times  IN  NUMBER) AS
BEGIN
  FOR i IN 1 .. p_times LOOP
    do_something_2(p_times => p_times);
  END LOOP;
END;                                       |           1 |      31967 |    31967 |    31967 |
+-------+-------------+-----------+-----------+-------------+----------------+-------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------+------------+----------+----------+
3 rows in set (0.117 sec)

注意事项

调试存储过程通过编译插桩实现，DBMS_PROFILER.start_profiler 会在在当前 package start profiler，所以抓不到当前 package 里的执行情况，如果想抓取当前 package A 的执行情况，需要嵌套一层 package B，通过 package B 调用 package A。
数据统计表生成在当前执行 DBMS_PROFILER 系统包的 schema 下。

数据统计表详情

提供以下表来记录汇总的统计信息：

-- plsql_profiler_runs
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';

此表用来记录剖析器每次启动的 runid 和时间、注释等信息。其中 runid 由 plsql_profiler_runnumber SEQUENCE 分配，只有启动剖析器时分配一次，预期不会有性能问题。

plsql_profiler_units
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';

此表用来记录每次执行中每个 PL 单元的信息，total_time 列需要使用 rollup_unit/rollup_run 接口手动更新，其他列会自动记录。

-- plsql_profiler_data
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';

影响租户

影响 OceanBase 数据库中的 Oracle 租户，对于 SYS 租户和 MySQL 租户无影响。

适用版本

OceanBase 数据库 V4.2.3 及之后版本。

手工通过黑屏 obclient 命令行调试 PL 代码

OceanBase 数据库 V4.x 中通过 PL cursor 去 fetch 数据时遇到了报错 ORA-01002: fetch out of sequence 的原因和解决方法

OceanBase 数据库