TKPROF:
————————–
TKProf is oracle provided trace reading utility which converts results in to more human readable format.
It required one to Enable SQL_Trace and set TIMED_Statistics which helps Oracle to create trace files with extra information.
Example:
SQL> alter session set timed_statistics = true;
Session altered.
SQL> alter session set sql_trace = true;
Session altered.
I’ve created a query to find my Oracle Server process id:
SELECT p.spid oracle_dedicated_process, s.process clientpid FROM v$process p, v$session s WHERE p.addr = s.paddr AND s.sid = (select sid from v$mystat where rownum = 1);
ORACLE_DEDIC CLIENTPID
———— ————
11653 11636
SQL> select * from scott.emp where job=’CLERK’;
EMPNO ENAME JOB MGR HIREDATE SAL COMM DEPTNO
———- ———- ——— ———- ——— ———- ———- ———-
7369 SMITH CLERK 7902 17-DEC-80 800 20
7876 ADAMS CLERK 7788 23-MAY-87 1100 20
7900 JAMES CLERK 7698 03-DEC-81 950 30
7934 MILLER CLERK 7782 23-JAN-82 1300 10
[oracle@localhost udump]$ ls -ltr
total 128
-rw-r—– 1 oracle oinstall 635 Jan 17 23:05 orcl_ora_11331.trc
-rw-r—– 1 oracle oinstall 692 Jan 17 23:05 orcl_ora_11358.trc
-rw-r—– 1 oracle oinstall 21454 Jan 17 23:08 orcl_ora_11359.trc
-rw-r—– 1 oracle oinstall 2862 Jan 17 23:31 orcl_ora_11653.trc
[oracle@localhost udump]$ tkprof orcl_ora_11653.trc Prashant_tkprof_study.txt
TKPROF: Release 10.2.0.1.0 – Production on Thu Jan 17 23:32:41 2013
Copyright (c) 1982, 2005, Oracle. All rights reserved.
[oracle@localhost udump]$ ls -ltr
total 145
-rw-r–r– 1 oracle oinstall 5925 Jan 17 23:32 Prashant_tkprof_study.txt
[oracle@localhost udump]$ cat Prashant_tkprof_study.txt
TKPROF: Release 10.2.0.1.0 – Production on Thu Jan 17 23:32:41 2013
Copyright (c) 1982, 2005, Oracle. All rights reserved.
Trace file: orcl_ora_11653.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
********************************************************************************
alter session set sql_trace = true
call count cpu elapsed disk query current rows
——- —— ——– ———- ———- ———- ———- ———-
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
——- —— ——– ———- ———- ———- ———- ———-
total 1 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
********************************************************************************
SELECT p.spid oracle_dedicated_process, s.process clientpid
FROM
v$process p, v$session s WHERE p.addr = s.paddr AND s.sid = (select sid from
v$mystat where rownum = 1)
call count cpu elapsed disk query current rows
——- —— ——– ———- ———- ———- ———- ———-
Parse 1 0.01 0.01 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 0 0 1
——- —— ——– ———- ———- ———- ———- ———-
total 4 0.01 0.01 0 0 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Rows Row Source Operation
——- —————————————————
1 NESTED LOOPS (cr=0 pr=0 pw=0 time=2133 us)
1 HASH JOIN (cr=0 pr=0 pw=0 time=2511 us)
1 FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=643 us)
1 COUNT STOPKEY (cr=0 pr=0 pw=0 time=20 us)
1 FIXED TABLE FULL X$KSUMYSTA (cr=0 pr=0 pw=0 time=14 us)
1 FIXED TABLE FULL X$KSUSGIF (cr=0 pr=0 pw=0 time=4 us)
20 FIXED TABLE FULL X$KSUPR (cr=0 pr=0 pw=0 time=43 us)
1 FIXED TABLE FIXED INDEX X$KSLED (ind:2) (cr=0 pr=0 pw=0 time=6 us)
********************************************************************************
select *
from
scott.emp where job=’CLERK’
call count cpu elapsed disk query current rows
——- —— ——– ———- ———- ———- ———- ———-
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 8 0 4
——- —— ——– ———- ———- ———- ———- ———-
total 4 0.00 0.00 0 8 0 4
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Rows Row Source Operation
——- —————————————————
4 TABLE ACCESS FULL EMP (cr=8 pr=0 pw=0 time=388 us)
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
——- —— ——– ———- ———- ———- ———- ———-
Parse 2 0.01 0.01 0 0 0 0
Execute 3 0.00 0.00 0 0 0 0
Fetch 4 0.00 0.00 0 8 0 5
——- —— ——– ———- ———- ———- ———- ———-
total 9 0.01 0.02 0 8 0 5
Misses in library cache during parse: 2
Misses in library cache during execute: 1
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
——- —— ——– ———- ———- ———- ———- ———-
Parse 0 0.00 0.00 0 0 0 0
Execute 0 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
——- —— ——– ———- ———- ———- ———- ———-
total 0 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
3 user SQL statements in session.
0 internal SQL statements in session.
3 SQL statements in session.
********************************************************************************
Trace file: orcl_ora_11653.trc
Trace file compatibility: 10.01.00
Sort options: default
1 session in tracefile.
3 user SQL statements in trace file.
0 internal SQL statements in trace file.
3 SQL statements in trace file.
3 unique SQL statements in trace file.
48 lines in trace file.
35 elapsed seconds in trace file.
Like this:
Like Loading...
Tales From A Lazy Fat DBA 