PLSQL - Measure the execution duration of a procedure

Question

I have a procedure that runs every one hour populating a table. The records handled from the procedure are many so it takes approximately 12~17 mins each time it is executed. Do you now if there is a way (i.e. trigger) to record the duration of each execution (i.e. into a table)?

score 7 · Accepted Answer · answered Mar 14 '11 at 19:09

7

I don't know of a trigger that would allow this to be done automatically. One way to do this would be something like

PROCEDURE MY_PROC IS
  tsStart  TIMESTAMP;
  tsEnd    TIMESTAMP;
BEGIN
  tsStart := SYSTIMESTAMP;

  -- 'real' code here

  tsEnd := SYSTIMESTAMP;

  INSERT INTO PROC_RUNTIMES (PROC_NAME, START_TIME, END_TIME)
    VALUES ('MY_PROC', tsStart, tsEnd);
END MY_PROC;

If you only need this for a few procedures this might be sufficient.

Share and enjoy.

answered Mar 14 '11 at 19:09

Bob Jarvis - Слава Україні

48,992
9
77
110

you could use `DBMS_UTILITY.GET_TIME` as well right @BobJarvis – Sathyajith Bhat Mar 15 '11 at 15:19
1

@Sathya: certainly DBMS_UTILITY.GET_TIME could be used, but the resolution of GET_TIME is only 1/100 of a second. That might work in this case where the function in question runs for multiple minutes, but in the case where you have a procedure which runs very quickly TIMESTAMPs would be better for recording start and end times. Of course, if a fast-running procedure is being timed a large number of records will be inserted into PROC_RUNTIMES, which is likely to fill up the associated tablespace rapidly. It's always something... :-) – Bob Jarvis - Слава Україні Mar 15 '11 at 15:32

score 1 · Answer 2 · answered Feb 16 '17 at 09:41

To add to the first answer, once you have start and end timestamps, you can use this function to turn them into a number of milliseconds. That helps with readability if nothing else.

function timestamp_diff(
  start_time_in timestamp,
  end_time_in timestamp) return number
as
  l_days number;
  l_hours number;
  l_minutes number;
  l_seconds number;
  l_milliseconds number;
begin
  select extract(day from end_time_in-start_time_in)
  , extract(hour from end_time_in-start_time_in)
  , extract(minute from end_time_in-start_time_in)
  , extract(second from end_time_in-start_time_in)
  into l_days, l_hours, l_minutes, l_seconds
  from dual;

 l_milliseconds := l_seconds*1000 + l_minutes*60*1000
   + l_hours*60*60*1000 + l_days*24*60*60*1000;

  return l_milliseconds;
end;

score 1 · Answer 3 · edited May 23 '17 at 11:55

I typically use a log table with a date or timestamp column that uses a default value of sysdate/systimestamp. Then I call an autonomous procedure that does the log inserts at certain places I care about (starting/ending a procedure call, after a commit, etc):

See here (look for my answer).

If you are inserting millions of rows, you can control when (how often) you insert to the log table. Again, see my example.

PLSQL - Measure the execution duration of a procedure

3 Answers3