Profiling PL/SQL Code - How to find out where your PL/SQL is spending its time

DBMS_PROFILER

For 8i->11g the DBMS_PROFILER interface is available. It has basic profiling functionality which includes:
  • The total number of times a line was executed
  • The the minimum, maximum, and average execution time of each line of code
  • How long SQL statements took to execute to completion
  • Code coverage (the actual lines executed during the analysis period
Here is a useful query to get the lines from a profiling run that took the most time per execution.
SELECT u.runid,
       u.unit_number,
       u.unit_type,
       u.unit_owner,
       u.unit_name,
       d.line#,
       d.total_occur,
       d.total_time,
       d.min_time,
       d.max_time,
       ROUND(((d.TOTAL_TIME/1000)/d.TOTAL_OCCUR),3) AS AVG_TIME_MS_PER_EXEC,
       USER_SOURCE.TEXT
FROM   plsql_profiler_units u
       JOIN plsql_profiler_data d ON u.runid = d.runid AND u.unit_number = d.unit_number
       RIGHT OUTER JOIN USER_SOURCE ON UNIT_NAME=NAME AND LINE#=LINE
WHERE  u.runid = :runid
  AND d.TOTAL_TIME > 0
ORDER BY ((d.TOTAL_TIME/1000)/d.TOTAL_OCCUR) DESC;

Hierarchical Profiler

For 11g there is a new Hierarchical Profiler available. This new profiler gives us a broader view of the execution of the PL/SQL. Instead of gathering detail about every line that executes, it gathers info about function calls and the call stack during the PL/SQL execution.
  • Detail on the parent-child relationships between function calls, count of function calls, and runtimes of functions.
  • Ability to 'Diff' two profiler runs - can show deltas between runs and get reports on improved/regressed SQL and PL/SQL
  • Less overhead for starting/ending profiling runs (no 'flush' required)
  • Faster to configure and use
While the Original and Hierarchical profilers are great for diagnosing performance issues keep in mind that they do not work in a vacuum. Elapsed time recorded by the proflier can be affected by other processes on your database server and skew results.