Call now: 252-767-6166  
Oracle Training Oracle Support Development Oracle Apps

 
 Home
 E-mail Us
 Oracle Articles
New Oracle Articles


 Oracle Training
 Oracle Tips

 Oracle Forum
 Class Catalog


 Remote DBA
 Oracle Tuning
 Emergency 911
 RAC Support
 Apps Support
 Analysis
 Design
 Implementation
 Oracle Support


 SQL Tuning
 Security

 Oracle UNIX
 Oracle Linux
 Monitoring
 Remote s
upport
 Remote plans
 Remote
services
 Application Server

 Applications
 Oracle Forms
 Oracle Portal
 App Upgrades
 SQL Server
 Oracle Concepts
 Software Support

 Remote S
upport  
 Development  

 Implementation


 Consulting Staff
 Consulting Prices
 Help Wanted!

 


 Oracle Posters
 Oracle Books

 Oracle Scripts
 Ion
 Excel-DB  

Don Burleson Blog 


 

 

 


 

 

 

 
 

Reading the Oracle 10046 Trace File sections, parse, execute, fetch & wait

Oracle Tips by Robert Freeman

Note: Here are related Oracle 10046 trace file notes:

Inside the Oracle 10046 Trace File Output

The trace file contains a great deal of information. Each cursor that is opened after tracing has been enabled will be recorded in the trace file. Here is a sample excerpt from a trace file:

=====================
PARSING IN CURSOR #2 len=79 dep=0 uid=73 oct=3 lid=73 tim=259898785365 hv=4060294543 ad='1cd62f00'
SELECT a.emp_first_name, b.job_name
FROM emp a, job b
WHERE a.job_key=b.job_key
END OF STMT
PARSE #2:c=0,e=154,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=259898785352
BINDS #2:
EXEC #2:c=0,e=12571,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=259898883135
WAIT #2: nam='SQL*Net message to client' ela= 10 p1=1111838976 p2=1 p3=0
FETCH #2:c=0,e=854,p=0,cr=14,cu=0,mis=0,r=1,dep=0,og=1,tim=259898908178
WAIT #2: nam='SQL*Net message from client' ela= 2120 p1=1111838976 p2=1 p3=0
WAIT #2: nam='SQL*Net message to client' ela= 6 p1=1111838976 p2=1 p3=0
FETCH #2:c=0,e=12470,p=0,cr=1,cu=0,mis=0,r=9,dep=0,og=1,tim=259898947719
WAIT #2: nam='SQL*Net message from client' ela= 1353028 p1=1111838976 p2=1 p3=0
XCTEND rlbk=0, rd_only=1
STAT #2 id=1 cnt=10 pid=0 pos=1 obj=0 op='HASH JOIN (cr=15 pr=0 pw=0 time=850 us)'
STAT #2 id=2 cnt=4 pid=1 pos=1 obj=55218 op='TABLE ACCESS FULL OBJ#(55218) (cr=7 pr=0 pw=0 time=168 us)'
STAT #2 id=3 cnt=10 pid=1 pos=2 obj=55217 op='TABLE ACCESS FULL OBJ#(55217) (cr=8 pr=0 pw=0 time=60 us)'
Let's break down this trace file into its constituent pieces:
 

Parse Phase of a 10046 Oracle trace

In this section of the trace file, we find the SQL statement and the parse record associated with the parse statement. My comments are in bold face:
 
This line provides information on the cursor itself. Here we see the length of the cursor (len=79), the user id of the person parsing the cursor (uid=73), the time the parse began (tim=) and the SQL address of the cursor (ad=). As you will see shortly, we can reference the ad= line to v$sqlarea and get the text of this cursor.
 
=====================
PARSING IN CURSOR #2 len=79 dep=0 uid=73 oct=3 lid=73 tim=259898785365 hv=4060294543 ad='1cd62f00'
 
This is the SQL statement itself. Note that terminator, END OF STMT.
 
SELECT a.emp_first_name, b.job_name
FROM emp a, job b
WHERE a.job_key=b.job_key
END OF STMT
 
This is the actual parse record. Note that many of the variables documented in this comment are reused in the execute and fetch records. The variables are:
 
C= cpu time, e=elapsed time, p=number of database blocks read, cr=number of consistent mode blocks read. cu=number of current mode blocks read, mis=number of library cache misses, r=number of rows, og=optimizer goal (1=all_rows, 2=first_rows, 3=rule and 4=choose). Also note that the cursor number is #2. Each cursor will be assigned its own number. Cursor numbers can be reused, so be careful about that!
 
PARSE #2:c=0,e=154,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=259898785352
 
Notice that the PARSE record is accompanied by the cursor number (#2 in this case).
 

Execute Phase of a 10046 Oracle trace

First of all, just in case this statement had bind variables, we have enabled tracing with a level 12, so Oracle will capture bind variable information for us. The bind variables will show up in the trace file at this point. Since we are not using bind variables, we move onto the execution (EXEC) phase which is represented by this line:
 
EXEC #2:c=0,e=12571,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=259898883135
 

Fetch Phase of a 10046 Oracle trace

Next, as all Oracle DBA's know, is the fetch phase. You might have noticed the WAIT record before the fetch; we will get to that next. Here is the fetch record. Notice that the variables listed are the same as the parse and execute records (though, of course, some values may be different).


FETCH #2:c=0,e=854,p=0,cr=14,cu=0,mis=0,r=1,dep=0,og=1,tim=259898908178
 

Those Evil Wait events in the 10046 trace file

The wait events are interspersed throughout the 10046 trace file.
 
WAIT #2: nam='SQL*Net message to client' ela= 10 p1=1111838976 p2=1 p3=0
 
In this wait record, we see that our wait event (nam) is SQL*Net message to client. These wait events are the same wait events you will find in the database in the v$ views like v$session_wait or v$event_name.
 
The elapsed time (ela) is in microseconds since we are on Oracle Database 10g, so this wait was a whole 10 microseconds. Nothing to worry about (1 second = 1,000,000 micro-seconds). The P1, P2 and P3 variables are specific to each event.
 
Here are some other examples of wait events you might see:
 
WAIT #7: nam='db file scattered read' ela= 1046 p1=10 p2=166987 p3=2
WAIT #7: nam='db file sequential read' ela= 509 p1=10 p2=166994 p3=1
WAIT #7: nam='buffer busy waits' ela= 26 p1=2 p2=1341 p3=231
WAIT #13: nam='latch free' ela= 0 p1=-2147427600 p2=103 p3=0
WAIT #15: nam='log buffer space' ela= 4 p1=0 p2=0 p3=0
WAIT #38: nam='file open' ela= 0 p1=0 p2=0 p3=0
 

Other Oracle trace records

Other records appear in 10046 trace files. For example, the execution plan of the statement executed is displayed with a series of STAT records as seen in the overall 10046 trace file we listed earlier in this paper.
 
Click here to read next section
Click here to read previous section

 
If you like Oracle tuning, see the book "Oracle Tuning: The Definitive Reference", with 950 pages of tuning tips and scripts. 

You can buy it direct from the publisher for 30%-off and get instant access to the code depot of Oracle tuning scripts.


 

 

��  
 
 
Oracle Training at Sea
 
 
 
 
oracle dba poster
 

 
Follow us on Twitter 
 
Oracle performance tuning software 
 
Oracle Linux poster
 
 
 

 

Burleson is the American Team

Note: This Oracle documentation was created as a support and Oracle training reference for use by our DBA performance tuning consulting professionals.  Feel free to ask questions on our Oracle forum.

Verify experience! Anyone considering using the services of an Oracle support expert should independently investigate their credentials and experience, and not rely on advertisements and self-proclaimed expertise. All legitimate Oracle experts publish their Oracle qualifications.

Errata?  Oracle technology is changing and we strive to update our BC Oracle support information.  If you find an error or have a suggestion for improving our content, we would appreciate your feedback.  Just  e-mail:  

and include the URL for the page.


                    









Burleson Consulting

The Oracle of Database Support

Oracle Performance Tuning

Remote DBA Services


 

Copyright © 1996 -  2017

All rights reserved by Burleson

Oracle ® is the registered trademark of Oracle Corporation.

Remote Emergency Support provided by Conversational