Gunther Oracle APEX und Datenbank Wiki

Diese Seite ist nicht editierbar. Sie können den Quelltext sehen, jedoch nicht verändern. Kontaktieren Sie den Administrator, wenn Sie glauben, dass hier ein Fehler vorliegt.
=====Oracle SQL Traces erzeugen und auswerten=====


{{ :images:ziege_lernt_sql.png?direct|Ziege lernt SQL}}

Alles was hinter einem ausgeführten SQL Befehle in der Datenbank steht, kann in einem Trace Files mit geschrieben werden. 


Die Trace Files werden vom dem Prozess geschrieben, der das SQL Kommando parst und ausführt.


Das Tracing kann auf der gesamten Datenbank, allen Sessionen, die sich über einen bestimmten Service anmelden und auf jeder Session aktiviert werden.

==== Alle aktuellen SQL Statements der Instance mit schreiben ====

Sehr unpraktisch, da viele Dateien und viele Daten erzeugt werden, recht mühsam in der Analyse.

Einschalten mit dem Parameter **sql_trace**
<code sql>
sqlplus / as sysdba

SQL>show parameter sql_trace

NAME                                 TYPE        VALUE
------------------------------------ ----------- -------
sql_trace                            boolean     FALSE


SQL>alter system set sql_trace=TRUE scope=memory;

# Trace Verzeichnis und Trace Datei der aktuellen Session:

select  value 
 from  v$diag_info 
where  name = 'Default Trace File';


VALUE
---------------------------------------------------
D:\ORACLE\diag\rdbms\gpi\gpi\trace\gpi_ora_2748.trc

#wieder ausschalten 

SQL>alter system set sql_trace=FALSE scope=memory;

</code>


=== Userid im Trace wieder erkennen ===

Wie erkenne ich nun aber von welchem User welcher Trace verursacht wurde?

Beispiel - Auszug aus dem Trace File:
<code sql>
PARSING IN CURSOR #368408184 len=43 dep=0 uid=88 oct=3 lid=88 tim=6948133230 hv=3912676408 ad='7ff2d6e3c58' sqlid='bbx3c0rnmdd1s'
</code>

In diesem Beispiel ist das die **"uid=88"**, mit der 88 als User ID dann in der dba_users suchen:

<code sql>
select username from dba_users where user_id=88;

USERNAME
--------
GPI

</code>




==== Trace auf alle Sessions mit speziellen Eigenschaften mit DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE ====

Beispiel -  Alle Sessions die sich über eine Service verbinden aufzeichnen:
<code sql>

begin
	DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE(
		 service_name  => 'SRVGPI'
		,module_name   =>  DBMS_MONITOR.ALL_MODULES
		,action_name   =>  DBMS_MONITOR.ALL_ACTIONS				
		,binds         =>  true
		,instance_name =>  null
		,plan_stat     =>  null
	);
 end;
/ 

</code>

==Überprüfen==
Über die View **dba_enabled_traces** prüfen, ob ein Trace eingeschaltet ist:
<code sql>
select trace_type
	  , primary_id
	  , qualifier_id1
	  , qualifier_id2
	  , waits
	  , binds
	  , plan_stats
	  , instance_name
 from dba_enabled_traces
order by
instance_name
/
</code>


Wieder ausschalten:
<code sql>

begin
   DBMS_MONITOR.serv_mod_act_trace_disable(
		 service_name  => 'SRVGPI'
		,module_name   =>  DBMS_MONITOR.ALL_MODULES
		,action_name   =>  DBMS_MONITOR.ALL_ACTIONS					
	);
 end;
/
</code>




==== Trace auf einer Sesssion bei bekannter SID====

In der eigenen Session einschalten:

<code sql>

begin
 dbms_monitor.session_trace_enable(
    session_id   => null,
    serial_num   => null,
    waits        => true,
    binds        => true,
    plan_stat    => null);
 end;
 /

-- session_id  Client Identifier for which SQL trace is enabled. If omitted (or NULL), the user's own session is assumed.
-- serial_num  Serial number for this session. If omitted (or NULL), only the session ID is used to determine a session.
-- waits       If TRUE, wait information is present in the trace
-- binds       If TRUE, bind information is present in the trace
-- plan_stat   Frequency at which we dump row source statistics. Value should be 'NEVER', 'FIRST_EXECUTION' (equivalent to NULL) or 'ALL_EXECUTIONS'.


</code>

<note tip>Wird mit "dbms_monitor.session_trace_enable" eine Session getracet ist nur in der v$session die Spalte SQL_TRACE gesetzt, wird aber "mit dbms_monitor.client_id_trace_enable" der Trace gestaret, wird der Trace in der View dba_enabled_traces angezeigt und NICHT mehr in der v$session!</note>

Und wieder ausschalten:
<code sql>
begin
dbms_monitor.session_trace_disable(
   session_id      => null,
   serial_num      => null);
end;
/

-- session_id 	Database Session Identifier for which SQL trace is disabled
-- serial_num 	Serial number for this session

</code>

see => 

  * http://docs.oracle.com/cd/E11882_01/appdev.112/e40758/d_monitor.htm#ARPLS67176
  * Tracing Enhancements Using DBMS_MONITOR (In 10g, 11g and Above) (Doc ID 293661.1)

==== Logon Trigger auf einem User ====


Per Logon Trigger wird das Tracing aktiviert:
<code sql >
CREATE OR REPLACE TRIGGER trg_logon
after logon
ON DATABASE
DECLARE
  PRAGMA AUTONOMOUS_TRANSACTION;
BEGIN
 --  Tracing aktivieren
 IF ora_login_user in ('SYS','DBSNMP','SYSMAN') THEN
    -- do nothing
 	NULL;
 ELSE
 	
        -- set trace file identifier to 
        execute immediate 'ALTER SESSION SET tracefile_identifier = '''||ora_login_user||'''';
       
        -- start trace
        dbms_monitor.session_trace_enable;

 	-- status in Log Tabelle schreiben 
 END IF;	
END;
/

# check if valid!
# test in other session if it is working BEFORE you close this session?

select status 
  from dba_triggers 
 where trigger_name='TRG_LOGON'
/

</code>

Ist der Trigger ungültig, kann keine Anmeldung an der DB erfolgen! Daher sorgfältig entwickeln!

**Tip: System Trigger auschalten** \\
Mit "ALTER SYSTEM SET "_system_trig_enabled" = FALSE SCOPE=BOTH;" kann ein System Trigger ausgeschaltet werden. Zur Not DB nur in nomount Status starten, spfile anpassen, DB öffnen und reparieren.

**Alternativ:**
Geht es nur um die Ameldung, klassisches Auditing in die aud$ Tabelle verwenden!


==== Traces bei bestimmten Events oder bestimmten Vorgängen einschalten====

**11g**\\


Ein Trace kann auch per Event eingeschaltet werden, zum Beispiel um die Details beim Erstellen eines Ausführungsplan zu erhalten.

=> siehe dazu [[dba:oracle_optimizer_trace|Oracle 11g - Einen Trace File vom Optimizer beim Erzeugen eines Plan anlegen]]


  * Alle Events lassen sich in SQL*Plus mit **oradebug doc event"** anzeigen
  * Alle Komponenten lassen sich in SQL*Plus mit **oradebug doc componet"** anzeigen.

Mit dem Befehl **<nowiki>ALTER SESSION SET events 'trace[<component>] disk=highest';</nowiki>** kann auf diese Komponente dann Trace aktiviert werden.

----




===== Trace Files auswerten =====


Mit **trcsess** können tracefiles aus mehreren Sessions zusammen fassen und mit **tkprof** auswerten.


Alternativ kann auch der Trace File direkt ausgewertet werden:


<code txt>

PARSING IN CURSOR #336124736 len=26 dep=0 uid=88 oct=3 lid=88 tim=12660074829 hv=1505019447 ad='7ff2d624ac0' sqlid='70dazgjcv9jjr'

select count(*) from col_t
END OF STMT


PARSE #336124736:c=0,e=1086,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=2309432470,tim=12660074828


EXEC #336124736:c=0,e=41,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2309432470,tim=12660074954


WAIT #336124736: nam='SQL*Net message to client' ela= 2 driver id=1111838976 #bytes=1 p3=0 obj#=-1 tim=12660075023

WAIT #336124736: nam='Disk file operations I/O' ela= 114 FileOperation=2 fileno=4 filetype=2 obj#=149923 tim=12660075388
...........


...........

WAIT #336124736: nam='direct path read' ela= 700 file number=4 first dba=23107 block cnt=5 obj#=149923 tim=12660076257


FETCH #336124736:c=530403,e=5840160,p=63138,cr=63149,cu=0,mis=0,r=1,dep=0,og=1,plh=2309432470,tim=12665915220

STAT #336124736 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=63149 pr=63138 pw=0 time=5840151 us)'
STAT #336124736 id=2 cnt=1570001 pid=1 pos=1 obj=149923 op='TABLE ACCESS FULL COL_T (cr=63149 pr=63138 pw=0 time=2160157 us cost=17264 size=0 card=1570001)'

WAIT #336124736: nam='SQL*Net message from client' ela= 286 driver id=1111838976 #bytes=1 p3=0 obj#=149923 tim=12665915667

FETCH #336124736:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=2309432470,tim=12665915742

WAIT #336124736: nam='SQL*Net message to client' ela= 1 driver id=1111838976 #bytes=1 p3=0 obj#=149923 tim=12665915787

WAIT #336124736: nam='SQL*Net message from client' ela= 3127 driver id=1111838976 #bytes=1 p3=0 obj#=149923 tim=12665918939

</code> 

==FETCH==


**FETCH #336124736:c=530403,e=5840160,p=63138,cr=63149,cu=0,mis=0,r=1,dep=0,og=1,plh=2309432470,tim=12665915220**



|#336124736 |=> |Cursor Handle für diesen Fetch|
|c=530403   |=> |Der Call hat 530403 +/- 10.000 uS CPU Zeit verbraucht|
|e=5840160  |=> |Der Call hat 5840160   +/- 1 uS verbrauchter Zeit gesamt|
|p=63138    |=> |Der Call hat 63138 Blöcke via OS read Call|
|cr=63149   |=> |Der Call hat 63149 Blöcke via "consistent mode" aus dem Buffer Cache gelesen|
|cu=0       |=> |Der Call hat 0 Blöcke via "current mode" aus dem Buffer Cache gelesen|
|mis=0      |=> |Der Call hat 0 misses gegen dem Oracle Library Cache|
|r=1        |=> |Der Call hat eine Row zurück gegeben|
|dep=0      |=> |Child level Falls > 0 ist es ein Call eines Child SQLs|
|op=1       |=> |Oracle Optimizer Goal 1=all,2=first,3=rule,4=choose|
|plh=2309432470 |=> |Hash Plan Value|
|tim=12665915220 |=> |Zeitstempel in +/- 1uS seit X, je nach Plattform, damit kann die echte Reihenfolge ermittelt werden!|

==OS Calls - Wait==


**WAIT #336124736: nam='direct path read' ela=700 file number=4 first dba=23107 block cnt=5 obj#=149923 tim=12660076257**


|#336124736 |=> |Cursor Handle für diesen Fetch|
|nam='direct path read' |=> |Event|
|ela=700                |=> |Der Call hat 700 700 +/- uS der verbrauchten Zeit|
|file number=4          |=> |Datei Nr|
|first dba=23107        |=> |
|block cnt=5     |=> | |
|obj#=149923     |=> |Der Call wurde auf dieser Objekt Id durchgeführt|
|tim=12660076257 |=> |Zeitstempel in +/- 1uS seit X, je nach Plattform, damit kann die echte Reihenfolge ermittelt werden! |



===== Quellen ====

Oracle:
  * http://docs.oracle.com/cd/E11882_01/appdev.112/e40758/d_monitor.htm


Trace:

  * http://www.oracle-base.com/articles/misc/sql-trace-10046-trcsess-and-tkprof.php#generating_sql_trace_files


Sehr gutes Papier für die Analyse:

  * http://method-r.com/papers
  * http://method-r.com/papers?download=72:sql-trace-data-(paper)


Optimizer Trace:

  * http://structureddata.org/category/oracle/optimizer/