23. Oktober 2008

Aktuelle Session Tracedatei ansehen: Mit SQL und PL/SQL

English title: Viewing Tracefiles with SQL and PL/SQL

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.
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
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. Das Skript kann nur in eine 11g-Datenbank eingespielt werden, da es V$DIAG_INFO erst in 11g gibt. Für frühere Versionen muss ich noch ein wenig Code zum Ermitteln der aktuellen Tracedatei zusammenstellen - das werde ich dann in einem späteren Posting veröffentlichen.
I'll -again- take the package for operating system interaction in order to create a PL/SQL package which does all the stuff automatically. This package TRACE_HELPER does only run in an Oracle11g database - previous versions don't have the V$DIAG_INFO view). To run in previous versions I have to write some code which determines the current session's tracefile ... this will be posted here when finished.
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
    SELECT value into v_filename FROM v$diag_info WHERE name = 'Default Trace File';
    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.

1 Kommentar:

Patrick Wolf hat gesagt…

Sehr nett! Das ist praktisch, denn auf den Datenbank Rechner kann man sich manchmal nicht einloggen oder muss dem Admin gut zureden... :-)

Beliebte Postings