TKPROF

SQL Trace and TKPROF

SQL Trace and TKPROF, Accrately assess the efficiency of the SQL Stat. an application runs.

SQL Trace:

Trace facility provide performance information on individual SQL Stat... It’s generating the following stat. for each stat.

1. Parse, execute and fetch counts

2. CPI and Elapsed Times

3. Physical Reads and logical Reads

4. Number of rows processed

5. Misses on the library cache

6. Username under which each parse occurred

7. Each commit and rollback

8. Wait event for each SQL Statement and a summary for each trace file.

TKPROF :

If you run TKPROF program to format the contents of the trace file and place the output into a readable output file

1. Create a SQL Script that stores the statistics in the database.

2. Determine the execution plan of SQL Stat.

Initialization Parameter to check before enables SQL Trace:

1. TIMED_STATISTICS = TRUE

2. MAX_DUMP_FILE_SIZE = 500 (By default)

3. USER_DUMP_DEST

4. SQL_TRACE= TRUE


DBMS_SESSION.SET_SQL_TRACE Procedure or

ALTER SESSION SET SQL_TRACE=TRUE

Identify Trace file:

            SELECT s.sid, s.serial#,  pa.value || '/' ||  LOWER(SYS_CONTEXT('userenv','instance_name'))

                        || '_ora_' || p.spid || '.trc' AS trace_file   FROM   v$session s, v$process p,  v$parameter pa

            WHERE  pa.name = 'user_dump_dest'   AND    s.paddr = p.addr

            AND    s.audsid = SYS_CONTEXT('USERENV', 'SESSIONID');

Output :



SID SERIAL#

---------- ----------

TRACE_FILE

--------------------------------------------------------------------------------

159 3

F:\ORACLE\PRODUCT\10.2.0\ADMIN\KEYSTONE\UDUMP/keystone_ora_4788.trc

Execute TKPROF Tool:

F:\oracle\product\10.2.0\admin\KEYSTONE\udump>tkprof keystone_ora_4788.trc babu1.txt explain=babu/babu TABLE=babu.plan_table sys=no waits=yes

TKPROF: Release 10.2.0.1.0 - Production on Mon Jun 11 18:35:52 2007

Copyright (c) 1982, 2005, Oracle. All rights reserved.

Babu1.txt file output:

TKPROF: Release 10.2.0.1.0 - Production on Mon Jun 11 18:49:51 2007

Copyright (c) 1982, 2005, Oracle. All rights reserved.

Trace file: keystone_ora_4788.trc

Sort options: default

********************************************************************************

count = number of times OCI procedure was executed

cpu = cpu time in seconds executing

elapsed = elapsed time in seconds executing

disk = number of physical reads of buffers from disk

query = number of buffers gotten for consistent read

current = number of buffers gotten in current mode (usually for update)

rows = number of rows processed by the fetch or execute call

********************************************************************************

The following statements encountered a error during parse:

SELECT S.SID,S.SERIAL#,PA.VALUE || '\' || LOWER(SYS_CONTEXT('USERENV','INSTANCE_NAME')) || '_ORA' || P.SPID || '.TRC'|| AS TRACE_FILE

FROM V$SESSION S, V$PROCESS P, V$PARAMETER PA

WHERE PA.NAME = 'USER_DUMP_DEST'

AND S.PADDR = P.ADDR

AND S.AUDSID = SYS_CONTEXT ('USERENV','SESSIONID')

Error encountered: ORA-00936

--------------------------------------------------------------------------------

SELECT s.sid, s.serial#, pa.value || '/' ||

LOWER(SYS_CONTEXT('userenv','instance_name'))

|| '_ora_' || p.spid || '.trc' AS trace_file

FROM v$session s,

v$process p,

v$parameter pa

WHERE pa.name = 'user_dump_dest'

AND s.paddr = p.addr

AND s.audsid = SYS_CONTEXT('USERENV', 'SESSIONID');

Error encountered: ORA-00911

********************************************************************************

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows

------- ------ -------- ---------- ---------- ---------- ---------- ----------

Parse 10 0.20 0.32 0 0 0 0

Execute 11 0.00 0.04 0 0 0 0

Fetch 16 0.03 0.07 0 0 0 19

------- ------ -------- ---------- ---------- ---------- ---------- ----------

total 37 0.23 0.44 0 0 0 19

Misses in library cache during parse: 7

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 5 0.00 0.00

SQL*Net message from client 4 1208.32 1208.43

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows

------- ------ -------- ---------- ---------- ---------- ---------- ----------

Parse 7 0.00 0.03 0 0 0 0

Execute 12 0.03 0.09 0 0 0 0

Fetch 12 0.00 0.01 1 29 0 5

------- ------ -------- ---------- ---------- ---------- ---------- ----------

total 31 0.03 0.14 1 29 0 5

Misses in library cache during parse: 5

Misses in library cache during execute: 3

11 user SQL statements in session.

14 internal SQL statements in session.

25 SQL statements in session.

0 statements EXPLAINed in this session.

********************************************************************************

Trace file: keystone_ora_4788.trc

Trace file compatibility: 10.01.00

Sort options: default

1 session in tracefile.

11 user SQL statements in trace file.

14 internal SQL statements in trace file.

25 SQL statements in trace file.

13 unique SQL statements in trace file.

435 lines in trace file.

3839 elapsed seconds in trace file.

Thanks & Regards

Babu B