Oracle SQL*Net Wait Events
Introduction
Unfortunately, what Oracle calls “Network Waits” most often have little to do with Network but and almost exclusively to do with the time it takes to pack messages for the network before they are sent.
Client = you, the tool, sqlplus, application
Not the client, the other side = the shadow process is communicating to the client
Of the three waits, only “more data” is possibly related to network issues and that’s not even clear, the other two are simply the time it takes to pack a message before sending it.
SQL*Net message to client – time to pack a message (no network time included) possibly tune SDU
SQL*Net more data from client – possible network issues, possibly tune SDU
SQL*Net more data to client – time to pack a message (no network time included) possibly tune SDU
The same events exist, but where the client is the shadow process and another database plays the roll of shadow process:
SQL*Net message to dblink
SQL*Net more data from dblink – possible network issues, possibly tune SDU
SQL*Net more data to dblink
SQL*Net Wait Events
SQL*Net message from client
Idle Event
Waiting for work from Client
Includes network transmission times for messages coming from shadow
Typically indicative of Client “think time” or “processing time”
Example from Egor Starostin, http://oracledba.ru
From a 10046 trace
=====================
PARSING IN CURSOR #1 len=43 dep=0 uid=0 oct=3 lid=0 tim=1304096237
hv=2707617103 ad=’89a03e18′
select * from all_objects where rownum < 20
END OF STMT
PARSE #1:c=0,e=143,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1304096209
EXEC #1:c=0,e=744,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1304097036
WAIT #1: nam=’SQL*Net message to client’ ela= 3 driver id=1650815232
#bytes=1 p3=0 obj#=-1 tim=1304097096
FETCH #1:c=10000,e=6903,p=0,cr=9,cu=0,mis=0,r=1,dep=0,og=1,tim=1304104057
1->WAIT #1: nam=’SQL*Net message from client‘ ela= 721 driver
id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1304104865 # [non-idle]
WAIT #1: nam=’SQL*Net message to client’ ela= 1 driver id=1650815232
#bytes=1 p3=0 obj#=-1 tim=1304105319
FETCH #1:c=0,e=627,p=0,cr=21,cu=0,mis=0,r=15,dep=0,og=1,tim=1304105524
2->WAIT #1: nam=’SQL*Net message from client‘ ela= 253 driver
id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1304105818 # [non-idle]
WAIT #1: nam=’SQL*Net message to client’ ela= 1 driver id=1650815232
#bytes=1 p3=0 obj#=-1 tim=1304105867
FETCH #1:c=0,e=63,p=0,cr=6,cu=0,mis=0,r=3,dep=0,og=1,tim=1304105900
3->WAIT #1: nam=’SQL*Net message from client‘ ela= 1960753 driver
id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1306066946 # [idle]
=====================
PARSING IN CURSOR #1 len=21 dep=0 uid=0 oct=3 lid=0 tim=1306069444
hv=2200891488 ad=’89913b50′
select user from dual
END OF STMT
PARSE #1:c=0,e=60,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=1306069440
…
The first two “SQL*Net message from client’ are in the middle of cursor processing and are considered non-idle waits.
The third “SQL*Net message from client” is between cursors and considered an idle event, ie we are waiting for the next command from the client.
Time it takes to pack a message to be sent to the client
Doesn’t include network timing
see Tanel Poder’s analysis of SQL*Net message to client
Same as SQL*Net message to client except this is for data that spans SDU packets.
Wait represents the time it takes to pack data.
Doesn’t include network timing
SQL*Net more data from client
The only SQL*Net wait that can indicate a possible NETWORK problem
Client is sending data to shadow that spans packets (think large data inserts, possibly large code blocks, large SQL statements)
Shadow waits for next packet.
Can indicate network latency.
Can indicate a problem with the client tool
Here is an example with ASHMON where the application server died mid-stream on inserts. The shadow processes were left waiting for completion of the message. You can see the regular load on the database on the left, then just past the middle the load crashes, and all that’s left is waits on “SQL*Net more data from client”
Possibly set SDU=32768 as well as setting RECV_BUF_SIZE and SEND_BUF_SIZE to 65536.
SQL*Net break/reset to client
Error in sql statement
Control C
Usually highlights and error in application
Example:
CREATE TABLE T1 (C1 NUMBER);
ALTER TABLE T1 ADD
(CONSTRAINT T1_CHECK1 CHECK (C1 IN ('J','N')));
ALTER SESSION SET EVENTS
'10046 TRACE NAME CONTEXT FOREVER, LEVEL 12';
INSERT INTO T1 VALUES (1);
Trace File
PARSING IN CURSOR #2 len=25 dep=0 uid=0 oct=2 lid=0 tim=5009300581224 hv=981683409 ad='8e6a7c10'
INSERT INTO T1 VALUES (1)
END OF STMT
PARSE #2:c=0,e=2770,p=0,cr=2,cu=0,mis=1,r=0,dep=0,og=1,tim=5009300581220
BINDS #2:
EXEC #2:c=0,e=128,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=5009300581418
ERROR #2:err=1722 tim=512952379
WAIT #2: nam='SQL*Net break/reset to client' ela= 31 driver id=1650815232 break?=1 p3=0 obj#=-1 tim=5009300581549
WAIT #2: nam='SQL*Net break/reset to client' ela= 92 driver id=1650815232 break?=0 p3=0 obj#=-1 tim=5009300581662
Unfortunately Oracle doesn’t give much information about debugging unless you are trace. If you don’t trace, the SQL won’t be captured because from Oracle’s point of view the problem statement isn’t an acceptable SQL statement so there is no SQL ID to track down.
These waits are the same as
SQL*Net message to dblink
SQL*Net more data from dblink
SQL*Net more data to dblink
SQL*Net break/reset to dblink
Analysis and Tuning
There isn’t much to do on the Oracle side for tuning. You can try optimizing the SDU and SEND_BUF_SIZE and RECV_BUF_SIZE.
For actually getting information on network speeds you will have to use something like
- ping
- tnsping
- network sniffer
SDU
The default SDU can be set in the sqlnet. ora
If it’s not set, the default is 2048
The max is 32768
The default,or the value in sqlnet.ora, can be overridden in the tnsnames. ora and the listener.ora. The client and server negotiate the size aggreeing on the smaller of the two settings.
(TDU – Transmission Data Unit – see note 44694.1 The TDU parameter has been deprecated in the Oracle Net v8.0 and beyond and is ignored. It is only mentioned here for backward compatibility.)
tnsnames.ora
V10G = (DESCRIPTION =
(SDU=32768)
(ADDRESS = (PROTOCOL = TCP)(HOST = fuji)(PORT = 1522))
(CONNECT_DATA =
(SERVER = DEDICATED) (SERVICE_NAME = v10g)
) )
listener.ora
SID_LIST_LISTENER =
(SID_LIST =
(SID_DESC =
(SDU=32768)
(SID_NAME = v10g)
(ORACLE_HOME = /export/home/oracle10)
))
Tracing
sqlnet.ora
trace_level_client=16
trace_directory_client=/tmp
trace_file_client=client.trc
trace_unique_client = true
trace_level_server=16
trace_directory_server=/tmp
trace_file_server=server.trc
client.trc
client_3582.trc:[12-JAN-2008 11:37:39:237] nsconneg: vsn=313, gbl=0xa01, sdu=32768, tdu=32767
more from Jonathan Lewis at http://www.jlcomp.demon.co.uk/sdu.html
RECV_BUF_SIZE and SEND_BUF_SIZE
see: http://download.oracle.com/docs/cd/B19306_01/network.102/b14212/performance.htm (or local copy)
The recommended size for these buffers (from Oracle’s docs) is at least
Network bandwidth * roundtrip = buffer min size
For example if the network bandwidth is 100mbs and the round trip time (from ping) is 5ms then
100,000,000 bits 1 byte 5 seconds
---------------- x ------ x --------- = 62,500 bytes
1 second 8 bits 1000
tnsnames.ora
V10G = (DESCRIPTION =
(SEND_BUF_SIZE=65536)
(RECV_BUF_SIZE=65536)
(ADDRESS = (PROTOCOL = TCP)(HOST = fuji)(PORT = 1522))
(CONNECT_DATA =
(SERVER = DEDICATED) (SERVICE_NAME = v10g)
) )
listener.ora
SID_LIST_LISTENER =
(SID_LIST =
(SID_DESC =
(SEND_BUF_SIZE=65536)
(RECV_BUF_SIZE=65536)
(SID_NAME = v10g)
(ORACLE_HOME = /export/home/oracle10)
))
sqlnet.ora
RECV_BUF_SIZE=65536
SEND_BUF_SIZE=65536
Thank you for this great post, SQL*NET wait event are almost always ignored because it is often a network or an application problem. tracert is a good solution to identify network problems.
Yes, too bad SQL*Net wait events aren’t more useful. Tools like traceroute and tcpdump are the way to go http://www.oraclerealworld.com/tcp-trace-analysis-for-nfs/
Pingback: SQL*Net message from client | Magnus Johansson Tuning Blog
Thanks so much. Very useful with details on SQL Net to resolve my production issue.