Help interpreting profiler results (DBMS_PROFILER)
446255Oct 3 2008 — edited Nov 25 2008Oracle 10.2.0.4 on Windows XP
I am using DBMS_PROFILER (invoked from allround automations' PL/SQL Developer tool) to investigate the performance of a complex PL/SQL procedure and am confused by the profiler output. I was hoping the forum could provide some help in interpretting the results.
1. Are the times shown by the profiler wall clock or CPU time?
2. The process takes ~70 seconds (wall clock) to run, but the profiler only accounts for ~35 seconds total. Is there a way to determine where the other time being spent?
Is the missing time the difference between wall clock and CPU? The process is very CPU intensive and I am testing on a single CPU laptop. The most likely explanation I
read is that Oracle is in the OS's run queue waiting for the CPU but this doesn't seem likely to me since there isn't much else going on on the laptop and the unaccounted
for time is very consistent between runs. I also tried creating a trace file (via alter session set event '10046 trace name context forever, level 12') and the trace file
analysis shows 78% of the time as unaccounted for.
3. The lines with the longest total execution time in the profiler report are procedure declarations in a package body or object type body, e.g.:
PROCEDURE RUN_FRE_PROCESS( p_PROCESS_ID IN PLS_INTEGER, p_REC_IN IN RECORD_TYPE_T, p_RESULT OUT FRE_PROCESS_T ) -- #1 takes 25% of total time
OVERRIDING MEMBER FUNCTION CREATE_OUTPUT_UDR( SELF IN OUT PARSE_EDIT_WIRELESS_T, p_REC_IN_ IN RECORD_TYPE_T ... ) -- #2 takes 10% of total time
What does this mean? How do you optimize a procedure declaration; I wouldn't think these are executable lines of code that would take any time.
I did try adding a NOCOPY modifier to the P_RESULT_OUT parameters to try to avoid having to deep copy the returned object type (which contains several nested objects and collections), but it made no measurable difference.
4. Are there any other methods of profiling, instrumenting the code, other tools, etc. that I could use to shed some more light on where the time is being spent so I can optimize this procedure? I am in the process of installing Oracle 11, which will allow me to use the new hierarchical PL/SQL profiler.
Notes:
- The procedure I am timing is pretty complex and calls a lot of child procedures which use dynamic SQL and a lot of Oracle object types.
- I have recompiled all packages with debug information and am invoking the profiler as SYSTEM so I should have privs to view the source of all packages