Wait Events 3 – What is Wrong with this Quote?

9 12 2010

December 9, 2010

(Back to the Previous Post in the Series)

While reading the “Oracle Tuning the Definitive Reference Second Edition” book I found a handful of interesting suggestions regarding Oracle wait events.  Previous articles on this blog have described the contents of 10046 trace files, and leveraged the contents of those files to explain various types of problems and/or unexpected behavior (for example: three part series reading 10046 trace files, EXPLAIN PLAN/AUTOTRACE/TKPROF liesORDERED hint not followedfour part series: Enterprise Edition and Standard Edition perform differently11.2.0.1 ODBC bug, etc.)  Take three minutes to analyze the following quote from page 451 of the book that describes Oracle Database wait events found in 10046 trace files:

“Those Evil Wait Events in the 10046 Trace File

The trace file contains lots of details and it is important to seek out the wait event notes as 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

This wait event record shows that the wait event (nam) is a SQL*Net message to client.  These wait events are the same wait events that can be found in the database in the v$ views like v$session_wait or v$event_name.

The elapsed time (ela) is in microseconds since this database is Oracle 10g, so this wait was a whole 10 microseconds.  This is nothing to worry about because 1 second = 1,000,000 microseconds.  Please note the P1, P2 and P3 variables are specific to each event.”

Keeping in mind that the book is printed after the release of Oracle Database 11.2.0.1 (and possibly 11.2.0.2 for some operating system platforms), what, if anything, is wrong with the above quote?

While my review of the book only provides an in-depth technical review of the first 200 pages of the book, this blog article series will dig into some of the pages that were not specifically included in the review.

The point of blog articles like this one is not to insult authors who have spent thousands of hours carefully constructing an accurate and helpful book, but instead to suggest that readers investigate when something stated does not exactly match what one believes to be true.  It could be that the author “took a long walk down a short pier”, or that the author is revealing accurate information which simply cannot be found through other resources (and may in the process be directly contradicting information sources you have used in the past).  If you do not investigate in such cases, you may lose an important opportunity to learn something that could prove to be extremely valuable.

Other pages found during a Google search of the phrase:

  • dba-oracle.com/t_10046_trace_file_parse_execute.htm

Actions

Information

5 responses

9 12 2010
Charles Hooper

This one might be more difficult than I originally thought. To help you out, take a look at these lines that were captured to a trace file on April 1, 2006:

...
Oracle Database 10g Release 10.2.0.2.0 - 64bit Production
...
WAIT #3: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=4518311899
WAIT #3: nam='SQL*Net message from client' ela= 141 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=4518312106
WAIT #3: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=4518312250
FETCH #3:c=0,e=130,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=2,tim=4518312326
...
9 12 2010
Charles Hooper

Maybe I should not have provided a trace file section that was captured on April Fool’s Day? :-)

To help you out, take a look at these lines that were captured to a trace file on December 11, 2005:

...
Oracle8i Release 8.1.7.3.0 - Production
...
WAIT #5: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1 p3=0
WAIT #5: nam='SQL*Net message from client' ela= 0 p1=1413697536 p2=1 p3=0
WAIT #5: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1 p3=0
FETCH #5:c=0,e=0,p=0,cr=1,cu=4,mis=0,r=1,dep=0,og=4,tim=369800029
...
10 12 2010
Flado

Yeah… For a 10g instance, the waits are missing some features (parameter names, obj#, tim). Indeed, they look suspiciously like 8i waits, in which case ela would be in centiseconds.
And ‘SQL*Net message to client’ is really a poor choice for an example, as it is one of the few “unreliable” events in the sense that neither the byte count nor the elapsed time are correct (http://www.freelists.org/post/oracle-l/SQLNet-Message-to-client-wait-on-batch-job,4).

Cheers,
Flado

10 12 2010
10 12 2010
Charles Hooper

Flado,

Thank you for the research. When I read this section of the book I immediately thought that there must be something missing from the trace file, after all my 10g (10.2.0.2) trace file explains the meaning of the p1, p2, and p3 parameters as well as including tim= values on those wait event lines. This book section, which was probably written by Robert Freeman when Oracle Database 10.1 was the latest release, probably should have been updated to reflect changes to the 10046 trace file that were made since 2004 or 2005. The Oracle-l thread that you linked to contained part of a trace file that was captured by Oracle Database 10.1.0.3, and I tried to fix the formatting of a section of that file below:

EXEC #25:c=0,e=627,p=0,cr=0,cu=8,mis=0,r=1,dep=0,og=4,tim=208054417197
WAIT #25: nam='SQL*Net message to client' ela= 5 p1=1229996800 p2=1 p3=0
WAIT #25: nam='SQL*Net message from client' ela= 862 p1=1229996800 p2=1 p3=0

From the output posted in the book, it could just as likely be from Oracle 8i as it could be from 10g R1, which would mean a significant wait of 0.1 seconds.

Good catch stating that the ‘SQL*Net message to client’ wait event probably is not the best wait event to use in an example directly below the heading “Those Evil Wait Events in the 10046 Trace File”. A couple of other articles that might be of interest:
* http://blog.tanelpoder.com/2008/02/10/sqlnet-message-to-client-vs-sqlnet-more-data-to-client/
* http://blog.tanelpoder.com/2008/02/07/sqlnet-message-to-client-wait-gotcha/
* http://sites.google.com/site/embtdbo/wait-event-documentation/oracle-network-waits

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s




Follow

Get every new post delivered to your Inbox.

Join 144 other followers

%d bloggers like this: