| René Nyffenegger's collection of things on the web | |
|
René Nyffenegger on Oracle - Most wanted - Feedback
- Follow @renenyffenegger
|
The meaning of count, cpu and elapsed in tkprof | ||
|
Be sure to also take a look at Basics of tkprof.
In order to demonstrate the meaning of count, cpu and elapsed in tkprof, three different and simple SQL statements are
executed. One of these SQL Statements is executed three times, one is executed twice and one is
executed once. The only thing these statements actually do is call dbms_lock.sleep.
set feedback off select spid from v,v where audsid= sys_context('userenv','sessionid') and addr=paddr; alter session set sql_trace=true; begin /* three times */ dbms_lock.sleep(1); end; / begin /* once */ dbms_lock.sleep(1); end; / begin /* three times */ dbms_lock.sleep(1); end; / begin /* twice */ dbms_lock.sleep(2); end; / begin /* twice */ dbms_lock.sleep(2); end; / begin /* three times */ dbms_lock.sleep(1); end; / alter session set sql_trace=false;
If these statements are run and the trace file is tkprof'ed, it produces the following output:
begin /* three times */ dbms_lock.sleep(1); end; call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 3 0.01 0.01 0 0 0 0 Execute 3 0.00 3.10 0 0 0 3 Fetch 0 0.00 0.00 0 0 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 6 0.01 3.11 0 0 0 3 Misses in library cache during parse: 1 Optimizer goal: CHOOSE Parsing user id: 206 -------------------- begin /* twice */ dbms_lock.sleep(2); end; call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 2 0.00 0.01 0 0 0 0 Execute 2 0.00 4.09 0 0 0 2 Fetch 0 0.00 0.00 0 0 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 4 0.00 4.10 0 0 0 2 Misses in library cache during parse: 1 Optimizer goal: CHOOSE Parsing user id: 206 -------------------- begin /* once */ dbms_lock.sleep(1); end; call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.01 0.01 0 0 0 0 Execute 1 0.00 1.03 0 0 0 1 Fetch 0 0.00 0.00 0 0 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 2 0.01 1.04 0 0 0 1 Misses in library cache during parse: 1 Optimizer goal: CHOOSE Parsing user id: 206
The interesting parts are bold.
|