SQL _TRACE/10046 how to use events, detailed analysis

SQL _TRACE/10046 how to use events. A detailed analysis is a powerful tool provided by oracle for SQL tracking. It can track the parsing process, execution plan, and bind variables, recursive calling and so on first execute the TRACE command of SQL to generate the TRACE file, TKPROF format, and analyze the file

Alter session set SQL _trace = true to enable the SQL _trace function. Alter session set events '2017 trace name context forever, level 12'; enable the 10046 event.

 

LEVEL indicates the LEVEL set for the 10046 event. There are four categories: 1 -- enable the standard SQL _trace function, it is equivalent to SQL _trace 4 -- level 1 plus the binding value 8 -- level 1 wait time tracking 12 -- leve1 1 + leve 4 + level 8 or above. It can be seen that 10046 is actually an enhanced version of SQL _trace. Alter system can be used to modify global sessions. The local Tracing file generated is found in this path: E: \ oracle11g \ diag \ rdbms \ simon \ trace and then tkprof the formatted Information below the file:

TKPROF: Release 11.1.0.7.0 - Production on Thu Aug 1 14:39:34 2013Copyright (c) 1982, 2007, Oracle.  All rights reserved.Trace file: simon_ora_9168.trcSort options: default********************************************************************************count    = number of times OCI procedure was executedcpu      = cpu time in seconds executing elapsed  = elapsed time in seconds executingdisk     = number of physical reads of buffers from diskquery    = number of buffers gotten for consistent readcurrent  = number of buffers gotten in current mode (usually for update)rows     = number of rows processed by the fetch or execute call********************************************************************************ALTER SESSION SET SQL_TRACE=TRUEcall     count       cpu    elapsed       disk      query    current        rows------- ------  -------- ---------- ---------- ---------- ----------  ----------Parse        0      0.00       0.00          0          0          0           0Execute      1      0.00       0.00          0          0          0           0Fetch        0      0.00       0.00          0          0          0           0------- ------  -------- ---------- ---------- ---------- ----------  ----------total        1      0.00       0.00          0          0          0           0Misses in library cache during parse: 0Misses in library cache during execute: 1Optimizer mode: ALL_ROWSParsing user id: SYS********************************************************************************BEGIN DBMS_SYSTEM.SET_EV(133,6,10046,0,'SIMON'); END;call     count       cpu    elapsed       disk      query    current        rows------- ------  -------- ---------- ---------- ---------- ----------  ----------Parse        1      0.00       0.00          0          0          0           0Execute      1      0.00       0.00          0          0          0           1Fetch        0      0.00       0.00          0          0          0           0------- ------  -------- ---------- ---------- ---------- ----------  ----------total        2      0.00       0.00          0          0          0           1Misses in library cache during parse: 0Optimizer mode: ALL_ROWSParsing user id: SYS********************************************************************************BEGIN DBMS_SYSTEM.SET_EV(133,6,10046,8,'SIMON'); END;call     count       cpu    elapsed       disk      query    current        rows------- ------  -------- ---------- ---------- ---------- ----------  ----------Parse        2      0.00       0.01          0          0          0           0Execute      2      0.00       0.00          0          0          0           2Fetch        0      0.00       0.00          0          0          0           0------- ------  -------- ---------- ---------- ---------- ----------  ----------total        4      0.00       0.01          0          0          0           2Misses in library cache during parse: 0Optimizer mode: ALL_ROWSParsing user id: SYSElapsed 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********************************************************************************SELECT SID,SERIAL#,USERNAME FROM V$SESSION WHERE USERNAME='SIMON'call     count       cpu    elapsed       disk      query    current        rows------- ------  -------- ---------- ---------- ---------- ----------  ----------Parse        2      0.01       0.00          0          0          0           0Execute      2      0.00       0.00          0          0          0           0Fetch        4      0.00       0.00          0          0          0           4------- ------  -------- ---------- ---------- ---------- ----------  ----------total        8      0.01       0.00          0          0          0           4Misses in library cache during parse: 1Optimizer mode: ALL_ROWSParsing user id: SYSRows     Row Source Operation-------  ---------------------------------------------------      2  NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=0 size=121 card=1)      2   NESTED LOOPS  (cr=0 pr=0 pw=0 time=56 us cost=0 size=108 card=1)      2    FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=48 us cost=0 size=82 card=1)      2    FIXED TABLE FIXED INDEX X$KSLWT (ind:1) (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)      2   FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=0 us cost=0 size=13 card=1)Elapsed times include waiting on following events:  Event waited on                             Times   Max. Wait  Total Waited  ----------------------------------------   Waited  ----------  ------------  SQL*Net message to client                       2        0.00          0.00  SQL*Net message from client                     2        4.22          4.22********************************************************************************alter session set events '10046 trace name context forever,level 12'call     count       cpu    elapsed       disk      query    current        rows------- ------  -------- ---------- ---------- ---------- ----------  ----------Parse        1      0.00       0.00          0          0          0           0Execute      1      0.00       0.00          0          0          0           0Fetch        0      0.00       0.00          0          0          0           0------- ------  -------- ---------- ---------- ---------- ----------  ----------total        2      0.00       0.00          0          0          0           0Misses in library cache during parse: 0Parsing user id: SYSElapsed 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.84          2.84********************************************************************************OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTScall     count       cpu    elapsed       disk      query    current        rows------- ------  -------- ---------- ---------- ---------- ----------  ----------Parse        6      0.01       0.01          0          0          0           0Execute      7      0.00       0.00          0          0          0           3Fetch        4      0.00       0.00          0          0          0           4------- ------  -------- ---------- ---------- ---------- ----------  ----------total       17      0.01       0.02          0          0          0           7Misses in library cache during parse: 1Misses in library cache during execute: 1Elapsed times include waiting on following events:  Event waited on                             Times   Max. Wait  Total Waited  ----------------------------------------   Waited  ----------  ------------  SQL*Net message to client                       4        0.00          0.00  SQL*Net message from client                     3        4.22          7.06OVERALL TOTALS FOR ALL RECURSIVE STATEMENTScall     count       cpu    elapsed       disk      query    current        rows------- ------  -------- ---------- ---------- ---------- ----------  ----------Parse        0      0.00       0.00          0          0          0           0Execute      0      0.00       0.00          0          0          0           0Fetch        0      0.00       0.00          0          0          0           0------- ------  -------- ---------- ---------- ---------- ----------  ----------total        0      0.00       0.00          0          0          0           0Misses in library cache during parse: 0    7  user  SQL statements in session.    0  internal SQL statements in session.    7  SQL statements in session.********************************************************************************Trace file: simon_ora_9168.trcTrace file compatibility: 10.01.00Sort options: default       1  session in tracefile.       7  user  SQL statements in trace file.       0  internal SQL statements in trace file.       7  SQL statements in trace file.       5  unique SQL statements in trace file.     100  lines in trace file.   99634  elapsed seconds in trace file.