Tracing


Tracing should have little impact on performance but the amount of trace data generated can be significant.

Trace one's own  sqlplus   connection


turning trace on

alter session set events '10046 trace name context forever, level 12';
alter session set max_dump_file_size = unlimited;

Run query or job, the either exit session or turn tracing off

alter session set events '10046 trace name context off';

Trace a different user's session

Find session to trace from v$session


column sid for 9999

column machine for a15
column terminal for a7
col program for a30
col schemaname for a10
col osuser for a10
col module for a30
col action for a10
col client_info for a25
col client_identifier for a15

select sid,machine,terminal,program,schemaname,osuser, 
         module,action,client_info, client_identifier,service_name 
from v$session where type='USER';


  SID MACHINE         TERMINA PROGRAM                        SCHEMANAME OSUSER     MODULE
----- --------------- ------- ------------------------------ ---------- ---------- ----------------
ACTION     CLIENT_INFO               CLIENT_IDENTIFI
---------- ------------------------- ---------------
  142 172.16.101.237  unknown JDBC Thin Client               SOE        oracle     New Order
           Swingbench Load Generator Swingbench

  164 172.16.101.237  unknown JDBC Thin Client               SOE        oracle     New Order
           Swingbench Load Generator Swingbench

  173 172.16.101.237  unknown JDBC Thin Client               SOE        oracle     Browse Products
           Swingbench Load Generator Swingbench

  177 172.16.101.237  unknown JDBC Thin Client               SOE        oracle     New Order
           Swingbench Load Generator Swingbench

  179 172.16.101.237  unknown JDBC Thin Client               SOE        oracle     Browse Products
           Swingbench Load Generator Swingbench

  193 arrowtest       pts/1   sqlplus@arrowtest (TNS V1-V3)  SYS        delphix    sqlplus@arrowtest (TNS V1-V3)

Translate the session SID to its ORAPID

Using the SID from the query above on v$session, translate the SID into the ORAPID

select
p.pid orapid
from v$process p, v$session s
where s.sid = &SID
and p.addr = s.paddr
/

Turn on tracing using the ORAPID

The  following commands have to be run as "sysdba" in sqlplus

connect / as sysdba
oradebug setorapid [orapid]
oradebug event 10046 trace name context forever, level 12;
oradebug unlimit
oradebug tracefile_name

turning tracing ff

oradebug event 10046 trace name context off;

Turning trace on for Oracle Applications / EBS


If using Oracle Applications or EBS, then use the menus in the UI under help -> trace session -> trace session with waits

Finding the trace file

If "oradebug" was used to turn tracing on, then "oradebug tracefile_name" will show the name of the tracefile.

If not using "oradebug" then first  find "user_dump_dest". In sqlplus run

SQL> show parameters user_dump_dest
NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
user_dump_dest                       string      /home/oracle/oracle10/product/
                                                 10.2.0/db_1/rdbms/log

go to that directory,  /home/oracle/oracle10/product/10.2.0/db_1/rdbms/log in this case
run "ls -ltr" and look at the most recent trace files. Look for the file that contains the trace information expected.


Relate Trace information


Find the SIDs of running jobs

In the case where the process to be traced is an Oracle job, the values for the SID for a job can be found with the following query:

select * from dba_jobs_running;


Tagging Session

To make it easier find sessions in v$session, one can tag sessions with various identifiers if one has access to the code the session runs.
The fields are set automatically:
    • Machine  - where the user is connection from
    • Terminal - 
    • Program - like "sqlplus@host (TNS V1-V3)" or "JDBC Thin Client"
    • command - 0,1,2,3 ... type of sql command
    • server  - DEDICATED
    • schemaname
    • osuser - operating system user of user connection to database
    • sql_id - if the sqltext is know the sql_id can be looked up in v$sqltext
but these fields are controlled by code in the 
application
    • action               
DBMS_APPLICATION_INFO.SET_ACTION(action_name => 'transfer from chk to sav');
    • module               -   is empty unless filled by the application with this call 
    DBMS_APPLICATION_INFO.SET_MODULE(
    module_name => 'add_employee',
    action_name => 'insert into emp');
    • client_info          -  is empty unless filled by the application with this call 
    exec dbms_application_info.set_client_info('TEST');
    • client_identifier - has to be filled in by app   ,  client identifier can be used directly as an argument to turn on tracing
 exec dbms_session.set_identifier('TEST');

Tracing Parallel Query


If the trace file primarily has these events
  • PX Deq: Execute Reply          
  • PX Deq: Signal ACK EXT        
  • PX Deq: Parse Reply          
  • PX Deq: Join ACK            
  • PX Deq: Signal ACK RSG     
  • PX Deq: Slave Session Stats
then it is a  trace of a  parallel query and the traces from the parallel query require all the trace files from each  slave sessions for analysis
see:   https://blogs.oracle.com/db/entry/how_to_get_a_10046_trace_for_a_parallel_query

The key is setting a trace file identifier

alter session set tracefile_identifier='delphix_latency_tests';
alter session set events '10046 trace name context forever, level 12';
The parallel query slave traces will be in the background_dump_dest. 

show parameters backaground_dump_dest

go to that directory and  grep for the identifier in the trace file directory and then pull over every trace that has the identifier.
The master trace file, ie the query coordinator (QC), will be in the user_dump_dest as usual. 

The following command can also be used to consolidate the PQ slaves into one tracefile. This can be done at the customer site or in house by using the "trcsess" program available in any Oracle install

trcsess clientid='delphix_latency_tests' output=toto *trc

parallel query reference:  http://www.orafaq.com/wiki/Parallel_Query_FAQ  

Alternative: Turning on Trace with SID and SERIAL#


If for some reason oradebug is not accessible, such as not having sqlplus access or there is no sysdba access the following package enables trace , but the user will require execute on this package granted  from sys user.

In the following examples
  • 127 is the Session ID, the "SID"
  • 29 is the serial#
execute sys.dbms_system.set_int_param_in_session(127,29,'max_dump_file_size',2147483647 );
execute sys.dbms_system.set_ev(127,29,10046,8,'');

set trace off

execute sys.dbms_system.set_ev(127,29,10046,0,'');


Tracing with UNIX process id


Trace via ospid, ie the UNIX process id, typically used when monitoring Oracle processes with UNIX command top

oradebug oraospid [ospid]

 find a session's Oracle process id, ie "pid" or "orapid"  and spid, the UNIX  process id of the running Oracle shadow process

select
     p.pid pid,   -- used for : oradebug setorapid
     p.spid ospid -- used for : oradebug setospid
     s.sid sid,
     s.serial#
from v$process p, v$session s
where s.sid = &1
and p.addr = s.paddr
/


Tracing in 11g

In version 11g all the previous methods of tracing work as well, but 11g has a new package to enable tracing   which has added benefit of seeing who is being traced in v$session

dbms_monitor.session_trace_enable(session_id => 127,
serial_num => 29,
waits => TRUE,
binds => FALSE)

In 11g when the above package is used one can verify that tracing is on in v$session

select sid, serial#,sql_trace,sql_trace_waits, sql_trace_binds from v$session;

The drawback is , I don't believe there is a trace file unlimit comand "dbms_monitor", to be investigated

Tracing the entire database


alter system set events '10046 trace name context forever,level 12'; 
alter system set events '10046 trace name context off'; 

Tracing with triggers

CREATE OR REPLACE TRIGGER set_trace
BEFORE DELETE ON soe.order_items
BEGIN
  dbms_session.set_identifier('delphix_latency_tests');
END;
/


 exec dbms_monitor.client_id_trace_enable('delphix_latency_tests',true,false);

fine grain audit, to set triggers on select statements: 
http://technology.amis.nl/2005/09/26/select-trigger-in-oracle-database-introducing-fine-grained-auditing/

Tracing with triggers on Peoplesoft


CREATE OR REPLACE TRIGGER DELPHIX_TRACE
BEFORE UPDATE OF RUNSTATUS ON PSPRCSRQST
FOR EACH ROW
WHEN ( NEW.runstatus = 7
AND OLD.runstatus != 7
AND NEW.prcstype = 'XXX'
AND NEW.prcsname = 'YYY'
)
BEGIN
  dbms_session.set_identifier('delphix_latency_tests');
END;
/

You have to know the name of the TYPE , the XXX, and the PROCESS , the YYY, and change these.
These values can be seen in the table

select prcstype, prcsname from psprcsrqst;

enable tracing:

exec dbms_monitor.client_id_trace_enable('delphix_latency_tests',true,false);

disable tracing after tests and drop the trigger

exec dbms_monitor.client_id_trace_disable('delphix_latency_tests');
drop trigger DELPHIX_TRACE;


references
Comments