Trace pl/sql performance with DBMS_PROFILER

Since Oracle 8i we can trace pl/sql like we can trace sql with tkprof. With DBMS_PROFILER you can measure the execution time of a pl/sql program unit.

DBMS_PROFILER gives insight into the following statistics:
- The number of times a piece of pl/sql was executed
- The total time spend on a piece of pl/sql code, including sql statements.
- Minimum and maximum time spend on a piece of pl/sql code
- Which code is executed during profiling.

Example code

This is an example on how to use DBMS_PROFILER:

Prerequisites.

The DBMS_PROFILER package is not automatically created on install of the database. Before you can use it, you should run the following scripts: as sys user run the $ORACLE_HOME/rdbms/admin/profload.sql script. As user that uses the profiler (or as sys with grants) run: $ORACLE_HOME/rdbms/admin/proftab.sql

Procedures

The DBMS_PROFILER package has the following procedures: Start_Profiler: begin data collection Stop_Profiler: stop data collection. Data is not automatically stored when the user disconnects. Flush_Data: flush data collected in user session. Can call at points in a run to get incremental data. Pause_Profiler: pause user data collection Resume_Profiler: resume data collection Get_Version (proc): gets the version of this api. Internal_Version_Check: verify that the DBMS_Profiler version works with this DB version.

Tables

The profiler-information is stored in the following tables: plsql_profiler_runs - information on profiler runs plsql_profiler_units - information on each lu profiled plsql_profiler_data - profiler data for each lu profiled

Run profile session

set serverout on enabled

declare
  run_id number;
begin
  run_id := dbms_profiler.start_profiler(
       to_char(sysdate,'DD-MM-YYYY HH24:MI:SS'));
  ..
  call pl/sql
  ..
  
  /* Clear data from memory and store it in profiler tables.*/
  dbms_profiler.flush_data; 
  dbms_profiler.stop_profiler;
end;

Report on profile session

In Oracle 8i, Oracle supplied a sql ${ORACLE_HOME}/plsql/demo/profrep.sql to report of the profiling results.

In Oracle 10g a sql ${ORACLE_HOME}/plsql/demo/profsum.sql is provided.

-- show procedures
        SELECT substr(u.unit_type,1,30),substr(u.unit_name,1,30)
        , ROUND(d.total_time/10000000,2) total, d.total_occur
        , d.min_time, d.max_time
      FROM plsql_profiler_units u,
           plsql_profiler_data  d
     WHERE u.runid       = &1
       AND u.unit_owner  'SYS'
       AND d.runid       = u.runid
       AND d.unit_number = u.unit_number
       AND ROUND(d.total_time/1000000000,2) > 0.00
     ORDER BY
           d.total_time DESC;
           
           

-- Top 10 slow statements
SELECT * FROM (
select trim(decode(unit_type,'PACKAGE SPEC','PACKAGE',unit_type)||
 ' '||trim(pu.unit_owner)||'.'||trim(pu.unit_name))||
' (line '|| pd.line#||')' object_name
, pd.total_occur
, pd.total_time
, pd.min_time
, pd.max_time
, src.text
, rownum sequencenr
from plsql_profiler_units pu
,    plsql_profiler_data pd
,    all_source src
where pu.unit_owner = user
and pu.runid = &1
and pu.runid=pd.runid 
and pu.unit_number = pd.unit_number
and src.owner = pu.unit_owner 
and src.type = pu.unit_type
and src.name = pu.unit_name 
and src.line = pd.line#
) where sequencenr