Introduction
Why Profile? When tuning SQL, it is easy because there is just the single SQL statement. With PL/SQL, there are SQL statements, SQL imbedded in implicit and explicit cursors, called routines (functions/procedures), and the PL/SQL code itself. When a PL/SQL routine is taking 5 minutes to run, exactly what code is taking how much time. This is the information that the PL/SQL profiler provides. Without this information, the person trying to tune the PL/SQL is only shooting in the dark, perhaps pulling out and tuning the SQL within the code, but otherwise has no idea what a PL/SQL routine is doing when it comes to time spent on each line of code.
The profiler is easy to setup and easy to use. Tools like Quest Software’s TOAD provides a nice GUI interface to this profiler.
Installation
The profiler has two scripts that setup the environment. Both are found in the
The PROFLOAD.sql script needs to be run as SYS (connect
The PROFTAB.sql script is recommended to be executed for each user desiring to run the DBMS_PROFILER package. This script sets up the three main tables: PLSQL_PROFILER_RUNS, PLSQL_PROFILER_UNITS, and the PLSQL_PROFILER_DATA. This script can be setup so that all the users share these tables but this topic is beyond the scope of this paper.
Understanding the Profiler Process
Profiling is initiated with the START_PROFILER program. Start this process then execute the PL/SQL routine to be profiled. When execution is done, run the STOP_PROFILER program. This will stop the profiling process and write the collected information to the profiler tables.
There are two more routines that control the collection of profiler data: PAUSE_PROFILER and RESUME_PROFILER. These routines might be useful if only certain statistics are of interest from a rather large PL/SQL program, or perhaps called subroutines are not desired to be profiled. These routines are typically imbedded in the PL/SQL code.
The FLUSH_DATA routine can also be called to periodically write the collected information to the profiler tables. This might be useful if the STOP_PROFILER routine is taking an excessive amount of time when profiling larger PL/SQL routines. This routine is typically embedded in the PL/SQL code.
When the START_PROFILER routine is started, the Oracle RDBMS collects a variety of information about the PL/SQL routine while it is being executed. The STOP_PROFILER then stops this collection process and writes the collected information to the three profiler tables.
These tables are then examined using SQL to view the results of the profiler collection.
Using the PL/SQL Profiler
There will be additional profiler information collected if the object being profiled has been compiled using the debug option.
This example will use this simple LOOPING_EXAMPLE code:
CREATE OR REPLACE PROCEDURE looping_example
IS
loop_counter NUMBER := 0;
BEGIN
FOR rec IN (SELECT *
FROM emp)
LOOP
loop_counter := loop_counter + 1;
DBMS_OUTPUT.put_line (
'Record ' loop_counter ' is Employee ' rec.ename
);
END LOOP;
DBMS_OUTPUT.put_line ('Procedure Looping Example is done');
END;
To capture PL/SQL profile information, execute the following statements. The comment submitted with the START command will be populated into the RUN_COMMENT in the PLSQL_PROFILER_RUNS table, see below.
SQL> execute DBMS_PROFILER.START_PROFILER(‘User0 Looping_Example’);
SQL>
SQL> execute LOOPING_EXAMPLE:
SQL>
SQL> execute DBMS_PROFILER.STOP_PROFILER;
This example code and the PROFILER_RPT.sql SQL*Plus script (runs all 3 SQL statements in an interactive script) are available from www.DanHotka.com .
The profiler populates three tables with related information. PLSQL_PROFILER_RUNS has information about each time the profiler is started, including the comment entered when the profiler session was initiated. The PLSQL_PROFILE_UNITS contains information about the PL/SQL code executed during the run. Each procedure, function, and package will have its own line in this table. The PLSQL_PROFILE_DATA contains the executed lines of code, code execution time, and more. The following SQL is useful in extracting the profiler information.
First, find the profiler run of interest. The RUN_COMMENT column has the
select runid, run_owner, run_date, run_comment
from plsql_profiler_runs;
RUNID RUN_OWNER RUN_DATE RUN_COMMENT ---------- --------------- --------- -------------------------
10 USER0 01-FEB-10 LOOPING_EXAMPLE_2/1/2010
In this SQL, enter the RUNID from the prior SQL statement. Oracle will place several lines of ‘
select runid, unit_number, unit_type, unit_owner, unit_name, unit_timestamp
from plsql_profiler_units
where unit_owner <> '
and runid = &rpt_runid;
RUNID UNIT_NUMBER UNIT_TYPE UNIT_OWNER
---------- ----------- --------------- --------------- --------------- --------- 12 4 PROCEDURE USER0 LOOPING_EXAMPLE 01-FEB-10
select pu.unit_name, pd.line#, pd.total_occur passes, round(pd.total_time / 1000000000,5) total_time, us.text text
from plsql_profiler_data pd, plsql_profiler_units pu, user_source us
where pd.runid = &rpt_runid
and pd.unit_number = &rpt_unitid
and pd.runid = pu.runid
and pd.unit_number = pu.unit_number
and us.name = pu.unit_name
and us.line = pd.line#
and us.type in ('PACKAGE BODY','PROCEDURE','FUNCTION');
UNIT_NAME LINE# PASSES TOTAL_TIME TEXT --------------- ---------- ---------- ---------- --------------------------------------------- LOOPING_EXAMPLE 1 1 .00032 PROCEDURE looping_example LOOPING_EXAMPLE 3 1 .00002 cursor emp_cur is LOOPING_EXAMPLE 4 1 1.25721 select ename LOOPING_EXAMPLE 5 0 .00011 from emp; LOOPING_EXAMPLE 6 1 .00005 loop_counter NUMBER := 0; LOOPING_EXAMPLE 9 1 0 BEGIN LOOPING_EXAMPLE 10 1 .00002 open emp_cur; LOOPING_EXAMPLE 12 1 .00436 fetch emp_cur into ename; LOOPING_EXAMPLE 14 15 .00031 while emp_cur%FOUND LOOPING_EXAMPLE 16 14 .00029 loop_counter := loop_counter + 1; LOOPING_EXAMPLE 17 14 .00398 DBMS_OUTPUT.put_line LOOPING_EXAMPLE 19 14 .01895 fetch emp_cur into ename; LOOPING_EXAMPLE 20 1 0 END LOOP; LOOPING_EXAMPLE 22 1 .00004 DBMS_OUTPUT.put_line LOOPING_EXAMPLE 24 1 .00107 close emp_cur;
This code cleans up the profiler tables.
delete from plsql_profiler_data;
delete from plsql_profiler_units;
delete from plsql_profiler_runs;
Summary
The PL/SQL Profiler is an essential tool when tuning PL/SQL and the SQL coded into these same routines. Without something like this profiler process, it is impossible to tell where the time is spend when tuning PL/SQL code.
