如何分析 Oracle 存储过程的端到端性能答案

【问题标题】：How to profile end to end performance of Oracle stored procedure如何分析 Oracle 存储过程的端到端性能
【发布时间】：2011-12-01 14:39:24
【问题描述】：

我想知道我的存储过程从外部进程访问数据库并说执行这个到数据库返回到该进程并说这里是你去执行的时间。

有没有一种简单易行的方法来完成这项非常基本的任务？

当然，报告存储过程执行期间发生的情况以及存储过程在执行每项任务（插入、plsql 字符串操作等）上花费了多少时间将是一个奖励，但我真的只是想要一些简单的东西并且易于使用。（而且免费）

【问题讨论】：

您考虑过dba 网站吗？这与编程无关（无论如何，它的措辞可能是我遗漏了一些东西。）
@Mat - 完全不同意。开发人员应该知道如何分析程序的性能。
@APC：我没这么说。我说在专门为数据库专业人员服务的网站上可能更合适。也不是：没有近距离投票 - 我只是想在这里提供帮助。
嗯，我想这和编程没有直接关系，但是作为一个写了很多sql的应用程序开发人员，我想知道这些信息。当我以前做很多 MSSql 开发时，SSMS 给了我更多的统计和执行信息，这是我在一个易于使用的好工具中可能想要的。我不知道如何在 Oracle 中获得与此相似的任何东西，而且不知道我的程序是如何执行的真的很困扰我。
@Mat - 好的，但是在 SO 上有很多数据库开发人员。即使我们的人数被 C# 人超过:(

标签： performance oracle stored-procedures plsql oracle10g

【解决方案1】：

如果您使用的是 Oracle 11g，您应该查看分层分析器 DBMS_HPROF。这是一个工具，它将为您提供 PL/SQL 程序中所有节点的经过时间。顾名思义，它对于调查调用程序的程序特别有用。它还标识了不同于函数调用的 SQL 语句的时间。 Find out more.

它是标准 11g 部署的一部分，因此是免费的。好吧，一旦您支付了许可证费用，它就是免费的 :)

默认情况下，DBMS_HPROF 包的权限不授予任何人。因此，您需要让具有 SYSDBA 访问权限的人才能正确看到您。分析还需要创建一些表。这些事情都不应该是问题，但我知道有时它们是。

唉，您使用的是早期版本。这样就只剩下 DBMS_PROFILER，它从 9i 就已经存在了。这基本上适用于单个程序。它的主要缺点是我们只能在我们拥有 CREATE 权限的程序上使用它（即，除非我们有 CREATE ANY PROCEDURE 权限，这通常意味着成为 DBA，否则只能在我们的模式中使用程序）。此外，为了分析嵌入式 SQL 语句，我们需要使用 DBMS_TRACE 包。 Find out more.

【讨论】：

问题是我们的开发和测试级数据库还没有升级到11g。
@kralco626 - 软件版本是您应该在问题中包含的信息。

【解决方案2】：

最简单、最便宜的选择您可以将事件记录到“调试”表并检查日志之间的持续时间，例如 ex。在将带有时间戳 a 的表插入到调试表之前记录事件。将带有时间戳 b 的表插入到调试表后记录事件。

如果您的存储过程超过 5 行，这会有点费时，但它仍然会帮助您。还要实现一个调试标志，因此当您需要记录时间戳时，将过程顶部的标志设置为 true，然后重新编译它。执行存储过程时，它将记录所有事件，完成调试后，将标志设置为 false 并重新编译。

【讨论】：

这并没有给我端到端的性能；而是充其量只是从开始到结束语句所花费的时间。
+1 可以在程序中的任何位置使用日志表（自主事务）。包装在一个包中，然后在您喜欢的地方简单地调用它。您可以通过日志表中的时间戳跟踪处理中各个点的时间。如果您愿意，可以添加除了简单消息之外的其他信息（调用函数、上下文等）。
另外，关于日志表（使用自治事务）的好处是您可以通过在进程运行时查询日志表来跟踪长时间运行的进程的日志。我相信分析器是事后设置，所以当你停止分析时你会得到你的信息。我想我只是喜欢好的 ole 日志表的灵活性。
我不同意这是最简单或最便宜的选择。任何需要我们更改代码的东西都不便宜，特别是如果我们正在构建一个需要与我们的实际代码一起部署到生产环境中的基础设施。（显然我们已经有了一个日志基础设施，这个反对意见是没有实际意义的，但我怀疑它不适用于这里。）此外，日志表并不能轻易地向我们显示哪些事件，更不用说哪些行占用了最多时间。我是检测和日志记录的忠实粉丝，但它们对分析我们的代码没有帮助。

【解决方案3】：

如果您希望将自己的时间间隔写入您的 PL/SQL 程序，下面是我的模板代码。此外，这不需要您的 DBA 的帮助。我的 DBA 通常不愿意让我更多地访问更多的东西。那，我讨厌等待他们真正给我访问权限。

/* This procedure is simply an example of parsing out an Elapsed time into their individual time parts */
/*   In other words it provides to the user the elapsed time in hours : minutes : seconds . milliseconds */

DECLARE

  G_START_TIME1     NUMBER        := DBMS_UTILITY.GET_TIME;
  G_START_TIME2     NUMBER        := DBMS_UTILITY.GET_TIME;
  vG_ELAPSED_TIME   VARCHAR2(200);

  /* Variables below are used for storing Elapsed time. */
  RETVAL           NUMBER;
  hourss            NUMBER;
  minutess          NUMBER;
  secondss          NUMBER;
  millisecondss     NUMBER;
    n_hrs         NUMBER := 360000;
    n_mins        NUMBER := 6000;
    n_secs        NUMBER := 100;
    n_sixty       NUMBER := 60;
    n_thirty      NUMBER := 30;
    n_ten         NUMBER := 10;

  v_PrintTime     VARCHAR2(200);


  /* The procedure below is simply used to simulate the passage of time */
  PROCEDURE waste_time(pn_Seconds NUMBER) IS

  n_CentiSeconds  NUMBER  :=  pn_Seconds * 100;
  n_ProgramStart  NUMBER  := DBMS_UTILITY.GET_TIME; /* dbms_utility_get_time returns times in hundreds of a second */

  BEGIN
    WHILE DBMS_UTILITY.GET_TIME < n_ProgramStart + n_CentiSeconds
    LOOP
      null;
    END LOOP;
  END waste_time;

BEGIN

  G_START_TIME1   :=    -2019618227; --dbms_utility.get_time;

  --waste_time(1);
  --dbms_output.put_line('1 Second Wasted'|| chr(10));

  G_START_TIME2   :=    G_START_TIME1 + 366110; ---2019619227; --dbms_utility.get_time;

  dbms_output.put_line('Start_time: '||G_START_TIME1);
  dbms_output.put_line('End_time:   '||G_START_TIME2||chr(10));

  vG_ELAPSED_TIME :=  G_START_TIME2 - G_START_TIME1;
  millisecondss   :=  vG_ELAPSED_TIME * n_ten;
  secondss        :=  vG_ELAPSED_TIME / n_secs;
  minutess        :=  vG_ELAPSED_TIME / n_mins;
  hourss          :=  vG_ELAPSED_TIME / n_hrs;

  dbms_output.put_line('Total Time: '||millisecondss ||' Milliseconds');
  dbms_output.put_line('Total Time: '||vG_ELAPSED_TIME ||' Centiseconds');
  dbms_output.put_line('Total Time: '||secondss ||' Seconds');
  dbms_output.put_line('Total Time: '||minutess ||' Minutes');
  dbms_output.put_line('Total Time: '||hourss ||' Hours');

  millisecondss   :=  mod(vG_ELAPSED_TIME * n_ten, 1000);            /* Milliseconds into Seconds.  Returns left over millisedonds */
  secondss        :=  trunc(mod(vG_ELAPSED_TIME / n_secs, n_sixty)); /* Seconds into hours.  Returns how many seconds are left over */
  minutess        :=  trunc(mod(vG_ELAPSED_TIME / n_mins, n_sixty)); /* Seconds into hours.  Returns how many seconds are left over */
  hourss          :=  trunc(vG_ELAPSED_TIME / n_hrs);                /* Spit out hours only using just trunc here.  Since we don't need to build up Days we can leave this as is */

  v_PrintTime     :=  hourss ||':'|| minutess ||':'|| secondss ||'.'|| millisecondss;

  dbms_output.put_line(chr(10) ||'Elapsed Time: '|| v_PrintTime);


END;

【讨论】：