How trace session in oracle 11g
This is very important in identifying , what is happening in a session etc. There are many ways to trace the session. This is very useful in trouble shooting the query.
How to trace a session :-
In a dedicated server there will be a single process for each session , so there will be a separate trace file for each session. The trace files are located in the “user_dump_dest”(parameter in pfile) location.
There will be so many trace files in that location. To identify the tracefile of particular session give a name for the file.
ALTER SESSION SET tracefile_identifier = mysqltrace;
This will create the trace file which contain the name “mysqltrace”.
To enable the trace for a particular session we can use the DBMS_MONITOR.SESSION_TRACE_ENABLE procedure. By using this we can trace other session or current session.
EXECUTE DBMS_MONITOR.SESSION_TRACE_ENABLE(session_id => 125,serial_num => 319,waits => TRUE, binds => FALSE);
session_id -> session id
serial_num -> Serial number
waits -> To print the waits in the trace file
binds -> To print the bind information in the trace file
To disable the trace use the below command.
EXECUTE DBMS_MONITOR.SESSION_TRACE_DISABLE(session_id => 125,serial_num => 319);
NOTE :
To execute the DBMS_MONITOR.SESSION_TRACE_ENABLE method we need dba privilages. Any user can also enable SQL tracing for their own session by using the DBMS_SESSION package.
EXECUTE DBMS_SESSION.SESSION_TRACE_ENABLE(waits => TRUE, binds => FALSE); — To enable the trace of current session
EXECUTE DBMS_SESSION.SESSION_TRACE_DISABLE(); — To disable the trace of current session
We can also use the parameter “sql_trace” parameter at session level to enable the trace.
ALTER SESSION SET sql_trace = true;
ALTER SESSION SET tracefile_identifier = mysqltrace;
To stop the trace
ALTER SESSION SET sql_trace = false;
we can get the “session id” and the “serial number” for a particular session using the below command.
SELECT SID, SERIAL#, USERNAME FROM V$SESSION;
SID SERIAL# USERNAME
———- ———- ——————————
125 313 TEST
126 361
128 291 SYS
129 5
EXAMPLE 1:-
SQL> ALTER SESSION SET tracefile_identifier = mysqltrace;
Session altered.
SQL> EXECUTE DBMS_MONITOR.SESSION_TRACE_ENABLE(session_id => 125,serial_num => 319,waits => TRUE, binds => FALSE);
PL/SQL procedure successfully completed.
SQL> select count(*) from test;
COUNT(*)
———-
1
SQL> insert into test values(1,’oguri’);
1 row created.
SQL> commit;
Commit complete.
SQL> select * from test;
ID_TEST
———-
NAME_TEST
——————————————————————————–
100001
srinivas oguri
1
oguri
SQL> set lines 1000
SQL> select * from test;
ID_TEST NAME_TEST
———- —————————————————————————————————-
100001 srinivas oguri
1 oguri
SQL> update test set id_test=100;
2 rows updated.
SQL> commit;
Commit complete.
SQL> EXECUTE DBMS_MONITOR.SESSION_TRACE_DISABLE(session_id => 125,serial_num => 319);
PL/SQL procedure successfully completed.
Now go to the location of user_dump_dest.
cd /oracle/11.2.0/database/log/diag/rdbms/oguri7/OGURI/trace
-rw-r—– 1 oracle oinstall 265 Jul 23 15:13 OGURI_ora_33292446_MYSQLTRACE.trm
-rw-r—– 1 oracle oinstall 13783 Jul 23 15:13 OGURI_ora_33292446_MYSQLTRACE.trc
Two files are generated. The .trc file is the trace file of our session.
To read the trace files we need a tool named “tkprof”.
syntax of tkprof command
tkprof infile outfile wait=[yes|no] sys=[yes|no] explain=username/password
infile : It is the inputfile
outfile : output file
wait : used to write the waitevents in the outputfile.
sys : weather to log the queries fired by sys user or not
explain : we need to provide user name and password who is having create session privilage , by using this the tkprof will log into the system , get the plans for the queries and write the plans to the output file.
[oracle@DWH_UAT_DB2:/oracle/11.2.0/database/log/diag/rdbms/oguri7/OGURI/trace]$tkprof OGURI_ora_33292446_MYSQLTRACE.trc output1 waits=yes sys=no explain=test/test
TKPROF: Release 11.2.0.3.0 – Development on Wed Jul 23 15:14:45 2014
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
Below is the output file of the tkprof.
cat output1.prf (cat the output file)
SQL ID: 7f86s32nh1xbb Plan Hash: 3859524075
update test set id_test=100
call count cpu elapsed disk query current rows
——- —— ——– ———- ———- ———- ———- ———-
Parse 1 0.00 0.00 0 1 0 0
Execute 1 0.00 0.00 0 3 3 2
Fetch 0 0.00 0.00 0 0 0 0
——- —— ——– ———- ———- ———- ———- ———-
total 2 0.00 0.00 0 4 3 2
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 46 (TEST)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
———- ———- ———- —————————————————
0 0 0 UPDATE TEST (cr=3 pr=0 pw=0 time=356 us)
2 2 2 TABLE ACCESS FULL TEST (cr=3 pr=0 pw=0 time=36 us cost=2 size=26 card=2)
Rows Execution Plan
——- —————————————————
0 UPDATE STATEMENT MODE: ALL_ROWS
0 UPDATE OF ‘TEST’
2 TABLE ACCESS (FULL) OF ‘TEST’ (TABLE)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
—————————————- Waited ———- ————
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 2.10 2.10
********************************************************************************
Tracing an entire instance :-
EXECUTE DBMS_MONITOR.DATABASE_TRACE_ENABLE(waits => TRUE, binds => FALSE, instance_name => ‘inst1’);– To enable the trace
EXECUTE DBMS_MONITOR.DATABASE_TRACE_DISABLE(instance_name => ‘inst1’); — To disable the trace
To ensure that wait events information is written to the trace file for the session like (logfile sync , db file sequential read etc), run the following SQL statement:
ALTER SESSION SET EVENTS ‘10046 trace name context forever, level 8’;
By this command it will write the wait event details to the trace files. like below
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
——- —— ——– ———- ———- ———- ———- ———-
Parse 6 0.00 0.00 0 1 0 0
Execute 7 6.74 80.24 2028 904 244066 100001
Fetch 0 0.00 0.00 0 0 0 0
——- —— ——– ———- ———- ———- ———- ———-
total 13 6.74 80.25 2028 905 244066 100001
Misses in library cache during parse: 4
Misses in library cache during execute: 1
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
—————————————- Waited ———- ————
SQL*Net message to client 8 0.00 0.00
SQL*Net message from client 8 57.02 151.38
SQL*Net break/reset to client 4 0.00 0.00
Disk file operations I/O 1 0.00 0.00
db file sequential read 2028 0.04 2.37
log file sync 3 0.00 0.00
log file switch completion 25 0.10 2.50
log file switch (checkpoint incomplete) 50 2.72 66.73
Example :
ALTER SESSION SET tracefile_identifier = mysqltrace;
alter session set sql_trace = true;
ALTER SESSION SET EVENTS ‘10046 trace name context forever, level 8’;
select * from test;
alter session set sql_trace = false;
Viswamitra's blog 