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. Also attached below are customized
scripts that are used in the example.
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.
Previous
Next
Back to DBAsupport.com