Tracing SQL Statements

6.
Tracing SQL statements
7/24/13 11:08 PM
Tracing SQL
statements
Janusz R. Getta
CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013
6. Tracing SQL statements
7/24/13 11:08 PM
"EXPLAINING" SQL statements

EXPLAIN PLAN statement of SQL
EXPLAIN PLAN FOR
SELECT E#, ENAME
FROM EMPLOYEE
WHERE SALARY > 20000;
Query plan
-----------------------------------------------------SELECT STATEMENT
TABLE ACCESS FULL EMPLOYEE
TABLE ACCESS FULL EMPLOYEE means that system plans to read
entire table EMPLOYEE in a block by block mode
Janusz R. Getta
7/24/13 11:08 PM

EXPLAIN PLAN statement
EXPLAIN PLAN FOR
SELECT ENAME, SALARY
FROM EMPLOYEE
WHERE E# = 007;
Query plan
-----------------------------------------------------SELECT STATEMENT
TABLE ACCESS BY INDEX ROWID EMPLOYEE
INDEX UNIQUE SCAN EMPLOYEE_PKEY
INDEX UNIQUE SCAN EMPLOYEE_PKEY means that system plans to
access and index EMPLOYEE_PKEY and with ROWID found to access
a table EMPLOYEE (TABLE ACCESS BY INDEX ROWID EMPLOYEE)
Janusz R. Getta
7/24/13 11:08 PM

EXPLAIN PLAN FOR
FROM EMPLOYEE NATURAL JOIN DEPARTMENT
WHERE BUDGET > 100000;
Query plan
-------------------------------------------------------------------SELECT STATEMENT
NESTED LOOPS
TABLE ACCESS BY INDEX ROWID DEPARTMENT
INDEX UNIQUE SCAN DEPARTMENT_PKEY
The system plans to use a nested loop implementation of join operator (NESTED
LOOPS). With each row selected from EMPLOYEE and each value of attribute DNAME the
system plans to access and index over primary key of DEPARTMENT (INDEX UNIQUE
SCAN DEPARTMENT_PKEY ) and later on with ROWID found to access a table
DEPARTMENT (TABLE ACCESS BY INDEX ROWID DEPARTMENT) in order to join the
rows from EMPLOYEE and DEPARTMENT
Janusz R. Getta
7/24/13 11:08 PM

EXPLAIN PLAN FOR
SELECT ENAME, SALARY /*+ USE_HASH */
FROM EMPLOYEE NATURAL JOIN DEPARTMENT
WHERE BUDGET > 100000;
Query plan
-------------------------------------------------------------------SELECT STATEMENT
FILTER
HASH JOIN
TABLE ACCESS FULL DEPARTMENT
The system plans to use a hash implementation of join operator (HASH JOIN) dues to
a hint /*+ USE_HASH */. The results of join will be filtered over a condition BUDGET
> 100000.
Janusz R. Getta
7/24/13 11:08 PM
Using AUTOTRACE in SQL*Plus

SET AUTOTRACE statement of SQL*Plus
SET AUTOTRACE TRACEONLY; /* TRACEONLY skips the results of SELECT */
FROM EMPLOYEE
WHERE E# = 007;
Execution Plan
---------------------------------------------------------0
SELECT STATEMENT Optimizer=CHOOSE (Cost=1 Card=1 Bytes=12)
1
0
TABLE ACCESS (BY INDEX ROWID) OF 'EMPLOYEE' (Cost=1
Card=1 Bytes=12)
2
INDEX (UNIQUE SCAN) OF 'EMPLOYEE_PKEY' (UNIQUE)
Execution plan is the same as reported by EXPLAIN PLAN statement

Cost means the costs calculated by a cost-based optimizer
Card means the estimated number of rows accessed by the operation
Card means the estimated number of bytes accessed by the operation
Janusz R. Getta
7/24/13 11:08 PM

The results of tracing
Statistics
---------------------------------------------------------0 recursive calls
0 db block gets
1 consistent gets
0 physical reads
0 redo size
155 bytes sent via SQL*Net to client
270 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
0 rows processed
The number of recursive calls means the number of SQL statements

executed by the system in order to process a given SQL statements
The number of db block gets means the number of times a data block
was requested and read either from disk or data buffer cache without
checking transactional consistency
Janusz R. Getta
7/24/13 11:08 PM

Statistics
---------------------------------------------------------0 recursive calls
0 db block gets
1 consistent gets
0 physical reads
0 redo size
0 sorts (memory)
0 sorts (disk)
0 rows processed
The number of consistent gets means the number of times a consistent

read (with checking transactional consistency) either from disk or data
buffer cache was requested
The number of physical reads means the total number of data blocks
read from disk storage
Janusz R. Getta
7/24/13 11:08 PM

Statistics
---------------------------------------------------------0 recursive calls
0 db block gets
1 consistent gets
0 physical reads
0 redo size
0 sorts (memory)
0 sorts (disk)
0 rows processed
Redo size denotes the total amount of redo data generated in bytes by the
traced statement
The total number of SQL*Net roundtrips to/from client means the
total number of messages sent to and received from the client
The total number of rows processed means the number of rows
processed during the execution of the traced statement
Janusz R. Getta
7/24/13 11:08 PM
Using SQL_TRACE in SQL

ALTER SESSION SET SQL_TRACE=TRUE statement
ALTER SESSION SET SQL_TRACE=TRUE;
FROM EMPLOYEE
WHERE E# = 007;
=====================
PARSING IN CURSOR #1 len=49 dep=0 uid=59 oct=3 lid=59 tim=619698093112
hv=595394454 ad='66ef9850'
FROM EMPLOYEE
WHERE E# = 007
END OF STMT
PARSE #1:c=15625,e=36140,p=4,cr=66,cu=0,mis=1,r=0,dep=0,og=4,tim=619698093107
EXEC #1:c=0,e=24,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=619698093207
FETCH #1:c=0,e=8740,p=1,cr=1,cu=0,mis=0,r=0,dep=0,og=4,tim=619698101989
*** 2004-07-12 13:43:13.000
A pretty cryptic trace is stored in a location determined by USER_DUMP_DEST in *.trc file
ALTER SESSION SET SQL_TRACE=FALSE;

Janusz R. Getta
10
7/24/13 11:08 PM
Using SQL_TRACE in SQL

Using tkprof
FROM EMPLOYEE
WHERE E# = 007
call
count
------- -----Parse
1
Execute
1
Fetch
1
------- -----total
3
cpu
elapsed
disk
query
current
-------- ---------- ---------- ---------- ---------0.00
0.03
4
66
0
0.00
0.00
0
0
0
0.00
0.00
1
1
0
-------- ---------- ---------- ---------- ---------0.00
0.04
5
67
0
rows
---------0
0
0
---------0
Misses in library cache during parse: 1

Optimizer goal: CHOOSE
Parsing user id: 59
The execution statistics contain information about number of times Parse, Execute,
and Fetch occurred (column count), total CPU time spent, (column cpu), elapsed
time required (column elapsed), number of disk physical reads required (column
disk), number of reads in consistent (column query) or current (column current)
mode, and number of rows processed (column rows)
Janusz R. Getta
11
7/24/13 11:08 PM
Using extended SQL trace

ALTER SESSION SET EVENTS'10046 trace name
context forever, level 8' statement
ALTER SESSION SET EVENTS '10046 trace name context forever, level 8'
FROM EMPLOYEE
WHERE E# = 007;
=====================
PARSING IN CURSOR #1 len=49 dep=0 uid=59 oct=3 lid=59 tim=818623840137 hv=595394454
ad='66ef7aa0'
FROM EMPLOYEE
WHERE E# = 007
END OF STMT
WAIT #1: nam='SQL*Net message to client' ela= 5 p1=1297371904 p2=1 p3=0
WAIT #1: nam='db file sequential read' ela= 8036 p1=11 p2=54093 p3=1
*** 2004-07-14 20:58:49.000
WAIT #1: nam='SQL*Net message from client' ela= 3 p1=1297371904 p2=1 p3=0
A pretty cryptic trace is stored in a location determined by USER_DUMP_DEST in *.trc file

ALTER SESSION SET EVENTS'10046 trace name context off'
Janusz R. Getta
12
7/24/13 11:08 PM

The elements of extended trace
=====================
ad='66ef7aa0'
FROM EMPLOYEE
WHERE E# = 007
END OF STMT
*** 2004-07-14 20:58:49.000
len=49 length of SQL statement

uid=59 user identifier
lid=59 privilege user id
hv=5 statement id
Janusz R. Getta
dep=0 so called "recursive depth"

oct=3 Oracle command type
tim=8 on some systems gettimeofday
ad='6 library cache address of the cursor
13
7/24/13 11:08 PM

=====================
ad='66ef7aa0'
FROM EMPLOYEE
WHERE E# = 007
END OF STMT
*** 2004-07-14 20:58:49.000
c=0 total CPU time consumed

e=31767 amount of elapsed time
p=4 number of blocks from reads
cu=0 number of blocks read in consistent mode
mis=1 number of library cache misses r=0 number of rows returned
dep=0 so called "recursive depth" og=4 optimizer goal (4 means CHOOSE)
tim=8 on some systems gettimeofday
Janusz R. Getta
14
7/24/13 11:08 PM

=====================
ad='66ef7aa0'
FROM EMPLOYEE
WHERE E# = 007
END OF STMT
*** 2004-07-14 20:58:49.000
nam='S name of "wait" event

ela= 5 elapsed time (in microseconds)
p1=1 , p2=1, p3=0 the names of parameters obtained from:
SELECT NAME, PARAMETER1, PARAMETER2, PARAMETER3
FROM V$EVENT_NAME
ORDER BY NAME;
Janusz R. Getta
15
7/24/13 11:08 PM
References
G. Harrison Oracle Performance Survival Guide, Prentice
Hall, 2010
C. Millsap, Optimizing Oracle Performance, O'Reilly and Assoc., 2003,
chapters 5, 6 (UoW Library)
C. Antognini,Troubleshooting Oracle Performance, Apress, 2008
Janusz R. Getta
16

Tracing SQL Statements

Uploaded by

Copyright:

Available Formats

Tracing SQL Statements

Uploaded by

Document Information

Original Title

Copyright

Available Formats

Share this document

Share or Embed Document

Sharing Options

Did you find this document useful?

Is this content inappropriate?

Copyright:

Available Formats

Tracing SQL Statements

Uploaded by

Copyright:

Available Formats

6.

Tracing SQL statements

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

6. Tracing SQL statements

"EXPLAINING" SQL statements

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

6. Tracing SQL statements

"EXPLAINING" SQL statements

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

6. Tracing SQL statements

"EXPLAINING" SQL statements

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

6. Tracing SQL statements

"EXPLAINING" SQL statements

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

6. Tracing SQL statements

Using AUTOTRACE in SQL*Plus

INDEX (UNIQUE SCAN) OF 'EMPLOYEE_PKEY' (UNIQUE)

Execution plan is the same as reported by EXPLAIN PLAN statement

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

6. Tracing SQL statements

Using AUTOTRACE in SQL*Plus

The number of recursive calls means the number of SQL statements

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

6. Tracing SQL statements

Using AUTOTRACE in SQL*Plus

The number of consistent gets means the number of times a consistent

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

6. Tracing SQL statements

Using AUTOTRACE in SQL*Plus

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

6. Tracing SQL statements

Using SQL_TRACE in SQL

ALTER SESSION SET SQL_TRACE=FALSE;

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

6. Tracing SQL statements

Using SQL_TRACE in SQL

Misses in library cache during parse: 1

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

6. Tracing SQL statements

Using extended SQL trace

A pretty cryptic trace is stored in a location determined by USER_DUMP_DEST in *.trc file

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

6. Tracing SQL statements

Using extended SQL trace

len=49 length of SQL statement

dep=0 so called "recursive depth"

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

6. Tracing SQL statements

Using extended SQL trace

c=0 total CPU time consumed

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

6. Tracing SQL statements

Using extended SQL trace

nam='S name of "wait" event

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

6. Tracing SQL statements

CSCI317/MCS9317 Database Performance Tuning, SCSSE, Spring 2013

You might also like