Profiling PL/SQL Code - How to find out where your PL/SQL is spending its time
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;
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.