UNIT_OWNER                       UNIT_NAME                 SECONDS   PERCENTAG
-------------------------------- ------------------------- --------- ---------
SYS                              UTL_FILE                     946.42     92.79

Unit #4: SYS.UTL_FILE - Total time:    946.42 seconds

sql->show parameter dictionary

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
O7_DICTIONARY_ACCESSIBILITY          boolean     TRUE

... DBMS_PROFILER shows UTL_FILE is performance issue...

no, it shows you are spending time there - but that may well be unavoidable. Please remember when looking at performance related metrics:

THERE WILL ALWAYS BE SOMETHING AT THE TOP

always - in statspack/awr - there will ALWAYS be a top five times events - ALWAYS.


... Is there any way to determine why UTL_FILE is the problem here? ...
you spend most of your time calling it - that is why. You'd need to look at your code to ask "am I doing this most efficiently"

for example:

for x in ( select * from t ) 
loop
   utl_file.put( x.c1 );
   utl_file.put( ' ' );
   utl_file.put_line( x.c2 );
end loop;

that would be horribly inefficient, this:

for x in ( select * from t ) 
loop
   utl_file.put_line( x.c1 || ' ' || x.c2 );
end loop;

would be better and:

l_buffer := null;
for x in ( select * from t ) 
loop
   l_buffer := l_buffer || chr(10) || x.c1 || ' ' || x.c2;
   if (length(l_buffer) >= 32760 - (max_len_c1+max_len_c2+5))
   then
       utl_file.put_line( l_buffer );
       l_buffer := null;
   end if;
end loop;
if (l_buffer is not null)
then
   utl_file.put_line( l_buffer );
end if;

would probably be "the best"



but basically, in your case, since UTL_FILE is wrapped and you have no insight into the code, you have what you have as far as metrics there. what if you knew that you spend 50% of your time on line 1323 in UTL_FILE - would that be of any use to you? (rhetorical question....) You are in fact getting the details for that supplied package - at least as many as makes sense to give you, more detail would provide you nothing.

... The plsql code is heavily instrumented utilizing UTL_FILE via a wrapper package but I would hope the instrumentation is not the sole cause of the performance issue. ...

that would depend on how you instrumented. Most of the times, you would have code that looks like:


if ( debug_flag )
then
utl_file stuff
end if;


but it sounds like you might be profiling with instrumentation turned on - which you shouldn't be doing - you should be running the code as you would in production.

So, switch off (DO NOT REMOVE - SWITCH OFF and if you cannot switch off - fix that, make it switchable) your instrumentation and run it as you would in production.


If yours is not switchable - there are many that are:

http://tylermuth.wordpress.com/2009/11/03/logger-a-plsql-logging-and-debugging-utility/

for example.


(if you have access to dbms_hprof, you'll be happier with that - yes, it'll give you a hierarchy - you'll see what units of yours spent the most time calling utl_file stuff - get sqldeveloper and use it)