Oracle's DBMS_PROFILER: PL/SQL Performance Tuning - Page 2

April 28, 2003

EXAMPLE on using DBMS_PROFILER
This is a simple example that I am providing just as a reference on how to use the Profiler. I will run profiler and debug the following routine for performance. Customized scripts that are used in the example can be found at the end of this article.

1. Creating my procedure.

E.g.: 
create or replace procedure am_perf_chk (pi_seq     in            number, 
                                         pio_status in out nocopy varchar2) is 
  l_dat date := sysdate; 
begin 
  if trunc(l_dat) = '21-sep-02' and pi_seq = 1 then 
    pio_status := 'OK'; 
  else 
    pio_status := 'Invalid tape loaded'; 
  end if; 
exception 
  when others then 
    pio_status := 'Error in am_perf_chek'; 
end; 

2. Calling the routine with profiler.
The above routine will be placed and called in the call_profiler.sql (script details given below). The pi_seq value is passed as 2.

	SQL> @d:\am\call_profiler.sql 
	Profiler started 
	Invalid tape loaded 
	PL/SQL procedure successfully completed. 
	Profiler stopped 
	Profiler flushed 
	runid:8 

3. Evaluating the execution time.
The evalute_profiler_results.sql is called to get the time statistics.

SQL> @d:\am\evaluate_profiler_results.sql 
Enter value for runid: 8 
Enter value for name: am_perf_chk 
Enter value for owner: scott 
      Line      Occur       Msec Text
---------- ---------- ---------- -------------------------------------------------------------------
         1                       procedure am_perf_chk (pi_seq     in            number,
         2                                              pio_status in out nocopy varchar2) is
         3          2   43.05965   l_dat date := sysdate;
         4                       begin
         5          1   86.35732   if trunc(l_dat) = '21-sep-02' and pi_seq = 1 then
         6          0          0     pio_status := 'OK';
         7                         else
         8          1   8.416151     pio_status := 'Invalid tape loaded';
         9                         end if;
        10                       exception
        11                         when others then
        12          0          0     pio_status := 'Error in am_perf_chek';!
        13          1   2.410361 end;
13 rows selected.

Code% coverage
--------------
    66.6666667

As you can see, line 3 shows execution time as 86 msec which can be improved on. The if statement is altered (if pi_seq = 1 and trunc(l_dat) = '21-sep-02' then) and the above process is repeated. The following is the new result:

      Line      Occur       Msec Text
---------- ---------- ---------- -------------------------------------------------------------------
         1                       procedure am_perf_chk (pi_seq     in            number,
         2                                              pio_status in out nocopy varchar2) is
         3          2  17.978816   l_dat date := sysdate;
         4                       begin
         5          1   8.419503   if pi_seq = 1 and trunc(l_dat) = '21-sep-02' then
         6          0          0     pio_status := 'OK';
         7                         else
         8          1   7.512684     pio_status := 'Invalid tape loaded';
         9                         end if;
        10                       exception
        11                         when others then
        12          0          0     pio_status := 'Error in !am_perf_chek';
        13          1    .731657 end;
13 rows selected.

Code% coverage
--------------
    66.6666667

As you can see, line 3 execution time is reduced from 86 msec to 8 msec for the tested scenario. The excess time was taken due to the trunc() built-in. Shifting this to the right prevents its execution if the first condition is false. This is a small example and you will be thrown more challenges when debugging bigger routines.

The profiler result also shows how much of the code was covered during execution. This would give us an idea of the extent of the code that was performance monitored. The idea is to try out various scenarios for executing the code and check on the profiler results to find out if any PL/SQL performance issues are encountered.

Logical analysis can be carried out if a particular piece of code is executed for a given scenario, when it should not be executing at all.