Session Tracefile ansehen: Nur mit SQL ... und jetzt auch in Oracle9i und Oracle10g

English title: Viewing Tracefiles with SQL and PL/SQL

Erstmal ein gutes Neues Jahr 2009 an alle!

Zu diesem Thema gab es im Oktober 2008 schonmal ein Posting, welches jedoch nur in Oracle11g lauffähig war. Damals habe ich versprochen, für Oracle10g und Oracle9i etwas nachzuliefern - und hier ist es:

First things first: Happy new Year 2009!

Last October I published a posting about viewing tracefiles with SQL and PL/SQL but this was only "supported" for Oracle11g. I promised to post a version for Oracle9i and Oracle10g as well - here it is ...

Man kommt als Entwickler des öfteren in die Situation, sich eine Tracedatei ansehen zu müssen ... zwei Beispiele:

• Wenn man einen SQL Trace aktiviert, um ein SQL-Kommando zu analysieren, werden die Informationen in die Tracedatei geschrieben
• Wenn man eine Java Stored Procedure laufen lässt und diese eine Exception auslöst, landet der Java-Fehler-Stack im Tracefile

Und in diesen Fällen bedeutet das, dass man die Datenbankumgebung verlassen, sich an der Datenbankmaschine anmelden, die Tracedatei suchen und ggfs. mit tkprof aufbereiten muss - erst dann kann man sich die Inhalte ansehen. Das ist zumindest mal aufwändig und manchmal hat man auch gar keine Login-Daten für das Betriebssystem der Datenbankmaschine. Speziell bei Application Express hat man vielfach nur den Zugang über die Web-Oberfläche.

Sometimes there are situations where developers have to look into the database's tracefiles. Here are two examples ...

• If you activate a SQL trace to analyze a particular SQL command then this information is being written into a tracefile
• If a java stored procedure (java in the database) throws an exception the java error stack is by default written to a tracefile

... and this means that you have to log into the operating system of the database machine, change to the tracefile directory, lookup the file, process it with tkprof (when necessary) and finally view the results. This costs at least time and in some cases you don't even have credentials for the operating system.

In Oracle11g gibt es eine nette, sehr hilfreiche Kleinigkeit: die View V$DIAG_INFO. Diese gibt den Namen des für die aktuelle Session gültigen Tracefiles wie folgt heraus:

In Oracle11g there's a nice very helpful new view: V$DIAG_INFO shows the name of the current sessions' tracefile as follows:

SQL> select value from v$diag_info where name='Default Trace File'
  2  /

VALUE
--------------------------------------------------------------------------------
/oracle/u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_6328.trc

In Oracle10g geht das auch - ist aber nicht so bequem. Man muss man dazu ein wenig SQL schreiben ...

This is also possible in Oracle10g. But then some SQL is required ...

select 
  c.value || file_pkg.get_path_separator || 
  lower(d.instance_name) || 
  case
    when b.server = 'DEDICATED' then '_ora_' 
    else '_'||lower(vs.name)||'_'
  end ||
  to_char(a.spid, 'fm99999')
  || '.trc' 
from v$process a, v$session b, v$parameter c, v$instance d, v$shared_server vs
where a.addr = b.paddr 
and b.audsid = userenv('sessionid') 
and c.name = 'user_dump_dest'
and a.addr = vs.paddr (+);

Als Ausgangspunkt habe ich das SQL dieses Blog-Postings von Pas Apicalla verwendet. Ich musste es allerdings ein wenig erweitern, so dass es auch für Shared Server-Sessions den richtigen Dateinamen liefert. Achtet darauf, dass Ihr SELECT-Privilegien an den beteiligten V$-Views habt.

I started using the SQL query in this blog posting from Pas Apicalla. I extended it a bit so that it returns the correct filename also for shared server sessions. Make sure that you have SELECT privileges on the here used V$-Views.

Damit entfällt das Suchen auf dem Server - das Tracefile-Verzeichnis kann durchaus mal viele Dateien enthalten. Man kann die View aber auch ganz anders nutzen ...

Ok - with this you don't have to search for the tracefile - you already know its name ... but this information can furthermore be used to simplify the whole process.

Ich nehme dazu mal wieder das Package zum Ausführen von Betriebssystem-Kommandos zur Hilfe - damit kann man die Datei direkt auslesen und sogar das tkprof-Utility direkt aus der Datenbank starten. Das folgende PL/SQL-Paket TRACE_HELPER macht genau das.

I'll -again- take the package for operating system interaction in order to create a PL/SQL package which does all the stuff automatically.

create or replace package trace_helper is
  function get_session_trace_file return clob;
  function get_session_tkprof_trace(
    p_recursive_sql  in number default 1,
    p_explain        in varchar2 default null,
    p_sort           in varchar2 default null
  ) return clob;
  procedure set_output_tempfile_prefix(p_prefix in varchar2);
end trace_helper;
/
sho err

create or replace package body trace_helper is
  C_TKPROF_COMMAND constant varchar2(200) := '/oracle/u01/app/oracle/product/11.1.0/bin/tkprof';
  C_OUTFILE_PREFIX constant varchar2(200) := '/tmp/tkprof_out';

  g_outfile_prefix varchar2(200) := C_OUTFILE_PREFIX;

  procedure set_output_tempfile_prefix(p_prefix in varchar2) is
  begin
    g_outfile_prefix := p_prefix;
  end set_output_tempfile_prefix;
  function get_trc_file_name return varchar2 is 
    v_filename varchar2(32767);
  begin
    $IF DBMS_DB_VERSION.VER_LE_10_2 $THEN  
      select 
        c.value || file_pkg.get_path_separator || 
        lower(d.instance_name) || 
        case
          when b.server = 'DEDICATED' then '_ora_' 
          else '_'||lower(vs.name)||'_'
        end ||
        to_char(a.spid, 'fm99999')
        || '.trc' into v_filename
      from v$process a, v$session b, v$parameter c, v$instance d, v$shared_server vs where a.addr = b.paddr 
      and b.audsid = userenv('sessionid') 
      and c.name = 'user_dump_dest'
      and a.addr = vs.paddr (+);
    $ELSE                                  
      SELECT value into v_filename FROM v$diag_info WHERE name = 'Default Trace File';
    $END
    return v_filename;
  end get_trc_file_name;

  function get_session_trace_file return clob is
  begin
    return file_pkg.get_file(get_trc_file_name).get_content_as_clob('iso-8859-1');
  end get_session_trace_file;

  function get_session_tkprof_trace(
    p_recursive_sql  in number default 1,
    p_explain        in varchar2 default null,
    p_sort           in varchar2 default null
  ) return clob is
    v_tkprof_command varchar2(32767) := C_TKPROF_COMMAND;
    v_tkprof_success number;
    v_tkprof_content clob;

    v_output_file    file_type;
  begin
    v_output_file := file_pkg.get_file(
      g_outfile_prefix || substr(get_trc_file_name, instr(get_trc_file_name, '/', -1) + 1)
    );
    v_tkprof_command := v_tkprof_command || ' ' || get_trc_file_name || ' ' || v_output_file.file_path;

    if p_explain is not null then
      v_tkprof_command := v_tkprof_command || ' explain=' || p_explain;
    end if;
    if p_recursive_sql = 0 then 
      v_tkprof_command := v_tkprof_command || ' sys=no';
    end if;
    if p_sort is not null then
      v_tkprof_command := v_tkprof_command || ' sort=' || p_sort;
    end if;  

    v_tkprof_success := os_command.exec(v_tkprof_command);
    v_tkprof_content := v_output_file.get_content_as_clob('iso-8859-1');
    v_output_file := v_output_file.delete_file();

    return v_tkprof_content;
  end get_session_tkprof_trace; 
end trace_helper;
/
sho err

Das entstandene Package sieht so aus ...

The resulting package looks like this:

FUNCTION GET_SESSION_TKPROF_TRACE RETURNS CLOB
 Argument Name                  Typ                     In/Out Defaultwert?
 ------------------------------ ----------------------- ------ --------
 P_RECURSIVE_SQL                NUMBER                  IN     DEFAULT
 P_EXPLAIN                      VARCHAR2                IN     DEFAULT
 P_SORT                         VARCHAR2                IN     DEFAULT
FUNCTION GET_SESSION_TRACE_FILE RETURNS CLOB
PROCEDURE SET_OUTPUT_TEMPFILE_PREFIX
 Argument Name                  Typ                     In/Out Defaultwert?
 ------------------------------ ----------------------- ------ --------
 P_PREFIX                       VARCHAR2                IN

ACHTUNG: Die Zeile mit dem Pfad zum tkprof Executable müsst Ihr an euere Umgebung anpassen ...

Attention: The line containing the path to the tkprof executable must be adjusted to your environment before using the package.

  C_TKPROF_COMMAND constant varchar2(200) := '/oracle/u01/app/oracle/product/11.1.0/bin/tkprof';

• Die Funktion GET_SESSION_TRACE_FILE liest das Tracefile der aktuellen Session aus und gibt es als CLOB zurück. Das ist bspw. bei Java in der Datenbank hilfreich, wenn eine Exception ausgelöst wurde und die Details im Tracefile stehen ...
• Die Function GET_SESSION_TKPROF_TRACE gibt eine mit dem tkprof-Werkzeug aufbereitete Version des Tracefile als CLOB zurück. Während dieses Prozesses wird von eine temporäre Datei (diese nimmt den aufbereiteten Text auf) erzeugt, deren Inhalte werden in einen CLOB kopiert und dieser dann zurückgegeben. Schließlich wird die temporäre Datei gelöscht. Das Verzeichnis, in welches diese temporäre Datei abgelegt wird, könnt Ihr mit der Konstante C_OUTFILE_PREFIX oder mit der Prozedur SET_OUTPUT_TEMPFILE_PREFIX beeinflussen.
• Die Prozedur SET_OUTPUT_TEMPFILE_PREFIX legt den Pfad und das Namens-Präfix für die eben erwähnte temporäre Datei fest.

Damit das ganze funktioniert, braucht euer Datenbankschema nun noch einige Privilegien ... das folgende Skript müsst Ihr als DBA ausführen und den TRCTEST durch euren DB User ersetzen.

• The function GET_SESSION_TRACE_FILE reads just the tracefile content and returns it as a CLOB. This is helpful when java stored procedures throw exceptions - you then see the java error stack in the returning CLOB.
• The function GET_SESSION_TKPROF_TRACE executes tkprof on the session's tracefile and returns the tkprof output as a CLOB. During this process a temporary file with the tkprof output is being created, its contents are then being copied into a CLOB and finally it's being deleted. The directory into which this temporary file is placed, is determined by the PL/SQL constant C_OUTFILE_PREFIX - so you might want to adjust this according to your environment. The directory and the filename prefix can also be adjusted by the procedure SET_OUTPUT_TEMPFILE_PREFIX.
• The procedure SET_OUTPUT_TEMPFILE_PREFIX is used to set the directory and filename prefix for the temporary file generated by tkprof.

Your database schema needs some privileges in order to use the package. Just run the following script as the SYS user and change the TRCTEST user to the database user you're working with.

 
-- execute privilege for the "tkprof" utility
begin
  dbms_java.grant_permission( 
    'TRCTEST',
    'SYS:java.io.FilePermission',
    '/oracle/u01/app/oracle/product/11.1.0/bin/tkprof', 
    'execute' 
  );
end;
/

-- read privilege for the tracefile directory
declare
  v_diag_dir varchar2(4000);
begin
  select value into v_diag_dir 
  from v$diag_info where name = 'Diag Trace';
 
  dbms_java.grant_permission( 
    'TRCTEST',
    'SYS:java.io.FilePermission',
    v_diag_dir || '/-', 
    'read' 
  );
end;
/

-- read and write privileges for a temporary directory
-- the temporary files for the tkprof output are placed here
begin
  dbms_java.grant_permission( 
    'TRCTEST',
    'SYS:java.io.FilePermission',
    '/tmp/-',
    'read,write' 
  );
end;
/

-- this grants write permission on STDIN
begin
   dbms_java.grant_permission(
     grantee =>           'TRCTEST',
     permission_type =>   'SYS:java.lang.RuntimePermission',
     permission_name =>   'writeFileDescriptor',
     permission_action => null
   );
end;
/

-- this grants read permission on STDOUT
begin
   dbms_java.grant_permission(
     grantee =>           'TRCTEST',
     permission_type =>   'SYS:java.lang.RuntimePermission',
     permission_name =>   'readFileDescriptor',
     permission_action => null
   );
end;
/

Fertig. Testen ...

That's it ... here's a test ...

SQL> alter session set sql_trace=true;

Session altered.

SQL> select ... from ...;

:
:

SQL> select trace_helper.get_session_tkprof_trace from dual;

GET_SESSION_TKPROF_TRACE
--------------------------------------------------------------------------------

TKPROF: Release 11.1.0.7.0 - Production on Wed Oct 22 02:36:46 2008

Copyright (c) 1982, 2007, Oracle.  All rights reserved.

Trace file: /oracle/u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_6380.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 f ...
:

Ihr bekommt die Infos also direkt im SQL*Plus oder dem Werkzeug, mit dem Ihr gerade arbeitet - ein Wechseln der Umgebung ist nicht mehr nötig ...

You can now see the tracefile information within SQL*Plus (or your database development tool) - changing the environment is no longer necessary.