Using DBMS_PROFILER to find bottleneck in a procedure


Problem

Slow PL/SQL procedure

When you work with Oracle you'll probably have a database bigger than 1MB and with lots of data comes lots of responsibility as well as lots of performance issues. There are lots of different way to analyze a performance issue and usually more than one way can help you to identify a bottleneck. When you already know that a certain SQL query is causing the problem, this is not what you need. When working with procedures, you sometimes don't even know where to start searching. 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. Feel free to replace this with something you really worry about.

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;

If you have a database administrator, you can skip the next steps, but if you're on a new database, you'll probably have to install the profiler. All the installation scripts you need are located in $ORACLE_HOME/rdbms/admin. In sqlplus, you can run this script if you simply prepend an @ in front of it.

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

Solution

Recipe #1 - Using DBMS_PROFILER to analyze procedure

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;

This will make sure that all the details about our procedure will be saved in a few tables.From these tables, we can pull a lot of information. The following query shows how much time every line of our procedure needed, please note that we are using the same profile name to select our data:

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

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.

Comments




Please sign-in to post a comment