gplivna.eu

Activating/deactivating trace

See also alternative ways to enable oracle trace.

 

ALTER SESSION SET max_dump_file_size = unlimited;

ALTER SESSION SET tracefile_identifier = 'blabla';

ALTER SESSION SET timed_statistics = true;

 

ALTER SESSION SET EVENTS '10046 trace name context forever, level 12';

ALTER SESSION SET EVENTS '10046 trace name context off';

 

exec dbms_system.ksdddt – prints out wall clock value

 

Parsing in cursor part

 

len    SQL text length

dep    recursive depth

uid    user id calling the statement

oct    oracle command type no OCI

lid    user id owning the statement e.g. package

tim    in 9i and above in microseconds, in < 9i in centiseconds

hv     statemend id

ad     library cache address assigned in V$SQL

 

Database calls

PARSE, EXEC, FETCH (ERROR, UNMAP, ERROR UNMAP) parts:

 

c      CPU time consumed by process, >= 9i micro, < 9i cs

e      amount of wall time that elapsed during the calll

p      physical reds

cr     consistent reads (may cause another reads from disk)

cu     current reads (read of the current content of a block)

mis    library cache miss (each causes hard parse)

r      number of rows returned

dep    recursive depth of cursor

og     optimizer goal (1–all_rows, 2–first_rows, 3-rule, 4-choose)

tim    see above

 

WAIT part

 

nam    name

ela    >= 9i in micro, < 9i in cs

p1, p2, p3    SELECT name, parameter1, parameter2, parameter3

              FROM v$event_name

              ORDER BY name;

 

WAITS are before database calls (PARSE, EXEC, FETCH)

 

BINDS part

 

dty    data type (OCI) Here you can find actual values for it

avl    length in bytes of bind variable

value  value

mxl    Maximum possible length for this datatype

mal, scl, pre, oacflg, oacflg2, size, offset, bfp, bln, flg -
For explanation of these abbreviations see Metalink Note 39817.1

 

events 10032, 10033 for sorting, 10104 for hash joins

ROW source operations STAT (only when cursor is closed):

 

id     unique id within STAT line set

cnt    number of rows returned

pid    parent id

pos    whatever

obj    object id of the row source op. If the op executes upon a db object

op     the name of RS operation

cr     consistent mode reads

r      number of Oracle blocks read with OSread calls

w      number of Oracle blocks write with OSread calls

tim    elapsed duration in micro

parent stats include children statistics

 

XCTEND    for commits and rollbacks

 

rlbk   1 – if rollback, 0 – otherwise

rd_only   1 if transaction changed no data in db

 

trace elapsed time formula

elapsed time

 

Levels    3210

0 – APPNAME, parsing in curs, PARSE, EXEC, FETCH, STAT, XCTEND

1 – nothing more

2 – binds (4)

3 – waits (8, 12)

 

Activating trace for another session

 

sys.dbms_system.set_bool_param_in_session(

       :sid, :serial, ‘timed_statistics’, true);

sys.dbms_system.set_int_param_in_session(

       :sid, :serial, ‘max_dump_file_size’, 2147483647);

sys.dbms_system.set_ev(:sid, :serial, 10046, 12, ‘’);

sys.dbms_system.set_ev(:sid, :serial, 10046, 0, ‘’);

 

Measures

 

~10 K LIOs/sec for each 100MHz for processor

~100 PIOs/sec

High LIO count ~> 10 LIO per non aggregated row per table in FROM clause

 

References

1. Optimizing Oracle Performance by Cary Millsap and Jeffrey Holt

2. Useful Constants for the Performance Analyst by Cary Millsap, Jeff Holt, http://www.hotsos.com/e-library/abstract.php?id=4

3. Interpreting Raw SQL_TRACE and DBMS_SUPPORT.START_TRACE output, Metalink Note 39817.1

4. Information about trace by Julian Dyke http://julian.dyke.users.btopenworld.com/com/Diagnostics/Trace/Trace.html