SQL*Net message to client wait isn’t really what it’s thought to be

Tanel Poder

2008-02-07

In a recent Oracle Forum thread a question came up how to use SQL*Net message to client wait events for measuring network latency between server and client. The answer is that you can’t use it for network latency measurements at all, due to how TCP stack works and how Oracle uses it.

I’ll paste my answer here too, for people who don’t follow Oracle Forums:

As I wrote in that reply, “SQL*Net message to client” does NOT measure network latency! It merely measures how long it took to put the response message into TCP send buffer on the server!

Once the response packet is put into TCP send buffer, Oracle server process continues on and starts waiting for SQL*Net message FROM client again. It’s up to TCP stack to deliver this packet from this point and Oracle server process has no way for measuring directly when did the packet arrive (it would have to start intercepting TCP ACK packets at kernel level for that).

This behaviour also explains why the SQL*Net message TO client waits are usually unbelievably short - like 1 microsecond etc. The light in vacuum travels only 300 meters in one microsecond, the signal in a cable travels much slower - yet when sending a single packet from London to Hong-Kong, we see just a few microsecond “response times”.

Example:

$ fgrep "SQL*Net message to client" sol10g_ora_837.trc | head
WAIT #8: nam="SQL*Net message to client" ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=16418611294
WAIT #7: nam="SQL*Net message to client" ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=16418644515
WAIT #5: nam="SQL*Net message to client" ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=16428803213
WAIT #5: nam="SQL*Net message to client" ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=16428880945
WAIT #5: nam="SQL*Net message to client" ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=16428927443
WAIT #5: nam="SQL*Net message to client" ela= 0 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=16428973661
WAIT #5: nam="SQL*Net message to client" ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=16429019250
WAIT #5: nam="SQL*Net message to client" ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=16429066742
WAIT #5: nam="SQL*Net message to client" ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=16429114761
WAIT #5: nam="SQL*Net message to client" ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=16429162471

Note that you can see longer times spent waiting for “SQL*Net message to client” when sending large amounts of data. This happens when your TCP send buffer gets full, thus TCP stack can not accept further packets. Sending will be blocked until the remote site sends back further ACK packets which state up to which byte in the TCP transmission stream it has received the data.

So, if you’re sending loads of data over a slow link or misconfigured TCP connection, the “SQL*Net message to client” wait time can be used as a low-confidence indicator of your SQL*Net throughput (in conjunction with “bytes sent via SQL*Net to client” metric), but never a measure of network latency!

Note that this is not OS platform specific, this is just how TCP and SQL*Net work.


NB! Check out 2020 online training classes here! Advanced Oracle Troubleshooting training, Advanced Oracle SQL Tuning training, Practical Linux Performance & Application Troubleshooting training. In addition to the online classes, all attendees will receive personal downloadable video recordings too!