TKPROF Everywhere

Lately, I was searching for a solution to let developers to “tkprof” their statements in the most non-intrusive way possible. Of course, a quite appealing solution I found was the one suggested by Tom Kyte in his “Effective Oracle by Design” book. The solution involves reading the user trace file from the server and returning the content of that trace through a pipelined table function. The result may be spooled into a file on the client side and, after that, “tkprof” may be executed for this local file. However, the problem I have is that me, personally, I use oracle instant client and I don't have tkprof on my local machine. Furthermore, I don't use sqlplus all the time, therefore I would really like to get the formatted tkprof output directly within a simple SQL-SELECT statement.

The solution is quite simple: instead of returning the raw trace file it's enough to run tkprof utility on the server with the user dump trace file as a parameter and, eventually, to return the final output.

In order to setup the needed environment we'll have to:

1.create the user which will own the “tkprof” framework:

grant create session, alter session, create procedure to tools identified by xxx;

2.grant additional privileges for this user:

grant select on sys.v_$process to tools;
grant select on sys.v_$session to tools;
exec dbms_java.grant_permission( 'TOOLS', 
  'SYS:java.lang.RuntimePermission', writeFileDescriptor', '' );
exec dbms_java.grant_permission( 'TOOLS', 
  'SYS:java.lang.RuntimePermission', 'readFileDescriptor', '' );

3.create the following java source object. This is needed in order to execute an external program in the OS environment (thanks again Tom for this, see the Java procedure for host calls on Unix environment question.):

create or replace and compile java source named util as
import java.io.*;
import java.lang.*;

public class Util extends Object
{

 public static int RunThis(String args)
 {
 Runtime rt = Runtime.getRuntime();
 int        rc = -1;

 try
 {
    Process p = rt.exec(args);

    int bufSize = 4096;
    BufferedInputStream bis =
     new BufferedInputStream(p.getInputStream(), bufSize);
    int len;
    byte buffer[] = new byte[bufSize];

    // Echo back what the program spit out
    while ((len = bis.read(buffer, 0, bufSize)) != -1)
       System.out.write(buffer, 0, len);

    rc = p.waitFor();
 }
 catch (Exception e)
 {
    e.printStackTrace();
    rc = -1;
 }
 finally
 {
    return rc;
 }
 }
}

4.Create the package which embeds the whole tracing logic:

create or replace package tkprof 
/**
  Provides the tkprof tracing feature to developers. This package is
  supposed to be used in developing environments only.
  
  Required rights (the owner of this package is supposed to be TOOLS):
  
  grant alter session to tools;
  grant select on sys.v_$process to tools;
  grant select on sys.v_$session to tools;
  
  exec dbms_java.grant_permission( 'TOOLS', 'SYS:java.lang.RuntimePermission', 'writeFileDescriptor', '' );
  exec dbms_java.grant_permission( 'TOOLS', 'SYS:java.lang.RuntimePermission', 'readFileDescriptor', '' );

*/
is

  /**
    The complete path along the name of the tkprof utility. Change this constant to fit to your
    environment. After that the following right is required:
    
    exec dbms_java.grant_permission( 'TOOLS', 'SYS:java.io.FilePermission', TKPROF.TKPROF_EXECUTABLE, 'execute' );
    
    If a RAC configuration is used than the path should be the same accross all nodes. If the ORACLE_HOME
    env variable is different between the RAC nodes then the value of the ORACLE_HOME should be get dynamically
    by using, for example, the DBMS_SYSTEM.get_env procedure or symbolinc links may be created in the OS
    environment of every RAC node.
  */
  TKPROF_EXECUTABLE constant varchar2(300) := '/opt/oracle/product/10.2.0/db_1/bin/tkprof';

  /**
    The directory where the user trace files are stored. May be found out using:

    show parameter user_dump_dest
    
    If a RAC configuration is used than the path should be the same accross all nodes. If not, then the value
    should be fetch dynamically from v$parameter view. Another approach would be to create symbolic links in the
    OS environment of every RAC node.
  */
  UDUMP_PATH constant varchar2(300) := '/opt/oracle/admin/rfd/udump';

  /**
    The name of the oracle directory object which points out to the above
    path. The owner of this package must have read privileges on this
    directory:
    
    create directory UDUMP_DIR as '/opt/oracle/admin/rfd/udump';
    grant read on directory UDUMP_DIR to tools;
  */
  UDUMP_DIR constant varchar2(30) := 'UDUMP_DIR';
  
  /**
    A simple type used to return the tkprof_output.
  */
  type tkprof_output is table of varchar2(4000);

  /**
    Enable tracing for the current session. 
  */
  procedure enable;
  
  /**
    Disable tracing for the current session.
  */
  procedure disable;
  
  /**
    Get the status of the tracing for the current session.
    
    #return 'TRUE' if the trace is enabled, 'FALSE' otherwise.
  */
  function is_enabled return varchar2;
  
  /**
    Get the tkprof content thorough a pipelined table function.

    #pi_tkprof_params additional parameters to tkprof
  */
  function output(pi_tkprof_params varchar2 := '') return tkprof_output pipelined;

end tkprof;
/

create or replace package body tkprof is

  g_unique_session_id varchar2(100);
  g_trace_file_name   varchar2(4000);
  g_is_enabled        boolean;

  function run(pi_cmd in varchar2) return number as
    language java name 'Util.RunThis(java.lang.String) return integer';

  procedure enable as
  begin
    execute immediate 'alter session set tracefile_identifier=''' ||
                      g_unique_session_id || '''';
    execute immediate 'alter session set timed_statistics=true';
    execute immediate 'alter session set max_dump_file_size=unlimited';
    execute immediate 'alter session set events ''10046 trace name context forever, level 12''';
    g_is_enabled := true;
    dbms_output.put_line('session tracing enabled under ' ||
                         g_unique_session_id || ' identifier.');
  end;
  
  function is_enabled return varchar2 as
  begin
    if g_is_enabled then
      return 'TRUE';
    else
      return 'FALSE';
    end if;
  end;

  procedure disable as
  begin
    execute immediate 'alter session set events ''10046 trace name context off''';
    g_is_enabled := false;
    dbms_output.put_line('session tracing disabled');
  end;

  function output(pi_tkprof_params varchar2 := '') return tkprof_output
    pipelined as
    l_status  pls_integer;
    l_bfile   bfile := bfilename(UDUMP_DIR, g_trace_file_name || '.prf');
    l_last    pls_integer := 1;
    l_current pls_integer;
  begin
    dbms_java.set_output(10000);
    l_status := run(TKPROF_EXECUTABLE || ' ' || UDUMP_PATH || '/' ||
                    g_trace_file_name || ' ' || UDUMP_PATH || '/' ||
                    g_trace_file_name || '.prf ' || pi_tkprof_params);
    if l_status != 0 then
      dbms_output.put_line('status: ' || l_status);
      dbms_output.put_line('ERROR: cannot produce the tkprof trace!');
      return;
    else
      dbms_lob.fileopen(l_bfile);
      loop
        l_current := dbms_lob.instr(l_bfile, '0A', l_last, 1);
        exit when(nvl(l_current, 0) = 0);
        pipe row(utl_raw.cast_to_varchar2(dbms_lob.substr(l_bfile,
                                                          l_current -
                                                          l_last + 1,
                                                          l_last)));
        l_last := l_current + 1;
      end loop;
      dbms_lob.fileclose(l_bfile);
    end if;
  exception
    when others then
      if dbms_lob.isopen(l_bfile) != 0 then
        dbms_lob.fileclose(l_bfile);
      end if;
      raise;
  end;

begin
  g_unique_session_id := sys_context('userenv', 'sessionid');
  select sys_context('userenv', 'instance_name') || '_ora_' ||
         ltrim(to_char(a.spid)) || '_' || g_unique_session_id || '.trc'
    into g_trace_file_name
    from v$process a, v$session b
   where a.addr = b.paddr
     and b.audsid = sys_context('userenv', 'sessionid');
end tkprof;
/

5.Change the TKPROF_EXECUTABLE and UDUMP_PATH constants to fit with your environment.
6.Create the UDUMP_DIR directory:

create directory UDUMP_DIR as '/opt/oracle/admin/rfd/udump';
grant read on directory UDUMP_DIR to tools;

7.Grant execute rights for tkprof executable:

exec dbms_java.grant_permission( 'TOOLS', 'SYS:java.io.FilePermission', 
TKPROF.TKPROF_EXECUTABLE, 'execute' );

8.Make the TKPROF package available to everybody:

grant execute on tools.tkprof to public;
create public synonym tkprof for tools.tkprof;

Okey, that's it! Now, let's test it:

fits_cr@RFD> exec tkprof.enable

session tracing enabled under 7154134 identifier.

PL/SQL procedure successfully completed.

fits_cr@RFD> select count(1) from rolmda;

  COUNT(1)
----------
        95

fits_cr@RFD> exec tkprof.disable;
session tracing disabled

PL/SQL procedure successfully completed.


fits_cr@RFD> select * from table(tkprof.output);

COLUMN_VALUE
--------------------------------------------------------------------------------------
TKPROF: Release 10.2.0.3.0 - Production on Thu Mar 27 15:13:06 2008
Copyright (c) 1982, 2005, Oracle.  All rights reserved.
Trace file: /opt/oracle/admin/rfd/udump/rfd3_ora_26618_7154134.trc
Sort options: default

********************************************************************************
count    = number of times OCI procedure was executed
cpu      = cpu time in seconds executing
elapsed  = elapsed time in seconds executing
disk     = number of physical reads of buffers from disk
query    = number of buffers gotten for consistent read
current  = number of buffers gotten in current mode (usually for update)
rows     = number of rows processed by the fetch or execute call
********************************************************************************

select /*+ index(idl_sb4$ i_idl_sb41) +*/ piece#,length,piece
from
 idl_sb4$ where obj#=:1 and part=:2 and version=:3 order by piece#

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      0.00       0.00          0          2          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.00       0.00          0          2          0           0

... and so on ...

I'm sure this package can be improved but as a proof of concept I think that it's more than enough. Likewise, I have to mention that this was tested on a 10gR2 database therefore I don't know if you can use it without any changes on a different Oracle database version.