DBMS_PROFILER to find bottleneck in a PL/SQL procedure

Hi,

There are lots of different way to analyze a performance issue when you are working with Oracle database and usually more than one way can help you to identify a bottleneck.

When working with procedures, you sometimes don't even know where to start searching the bottleneck. This is where a PROFILER can be very helpful, as it will show you which line and command is called how many times as well as the time it took to ran this command.

First, we create a dummy procedure we'd like to analyze. 

CREATE OR REPLACE PROCEDURE FIBONACCI AS

max_iterations NUMBER := 100;

num_1 NUMBER := 0;

num_2 NUMBER := 1;

num_3 NUMBER := 0;

BEGIN

FOR i IN 1..max_iterations LOOP

DBMS_OUTPUT.put_line(num_3);

num_3 := num_1 + num_2;

num_1 := num_2;

num_2 := num_3;

END LOOP;

END FIBONACCI;

/

Step #1 - Using DBMS_PROFILER to analyze procedure

First, you have to run the following script as SYS:

@$ORACLE_HOME/rdbms/admin/profload.sql

Next, you have to run the following script with each user you want to use the profiler:

@$ORACLE_HOME/rdbms/admin/proftab.sql

Within a PL/SQL block, we run our procedure but wrap it using dbms_profiler. The first parameter is a comment we can use to find our profile later:

BEGIN

DBMS_PROFILER.start_profiler('fibonacci_profile');

fibonacci;

DBMS_PROFILER.stop_profiler;

END;

/

We can pull a lot of information by using below query:

SELECT as_.line, ppd.total_occur, ppd.total_time/1000000 total_time, as_.text FROM plsql_profiler_data ppd INNER JOIN plsql_profiler_units ppu ON ppu.runid=ppd.runid AND ppu.unit_number=ppd.unit_number INNER JOIN plsql_profiler_runs ppr ON ppr.runid=ppd.runid INNER JOIN all_source as_ ON as_.TYPE=ppu.unit_type AND as_.owner=ppu.unit_owner AND as_.name=ppu.unit_name AND as_.line=ppd.line# WHERE ppr.run_comment='fibonacci_profile' ORDER BY as_.line;

07:15:02 SQL> /

      LINE TOTAL_OCCUR TOTAL_TIME TEXT

---------- ----------- ---------- ----------------------------------------

         1           0    .001781 PROCEDURE FIBONACCI AS

         2           1          0    max_iterations NUMBER := 100;

         3           1          0    num_1 NUMBER := 0;

         4           1          0    num_2 NUMBER := 1;

         5           1          0    num_3 NUMBER := 0;

         7         101    .023155    FOR i IN 1..max_iterations LOOP

         8         100    .338427       DBMS_OUTPUT.put_line(num_3);

         9         100    .026717       num_3 := num_1 + num_2;

        10         100    .022264       num_1 := num_2;

        11         100    .018702       num_2 := num_3;

        13           1     .00089 END FIBONACCI;

11 rows selected.

You can sort this by the total_time to find the biggest bottle neck or by total_occur to find a part in the code which is called (too) many times.

Cheers !!!