SQL*Net Compression – 2

SQL*Net Compression – 2:
I wrote a note a few years ago about SQL*Net compression (this will open in a new window so that you can read the posts concurrently), showing how the order of the data returned by a query could affect the amount of network traffic. An example in the note demonstrated, using autotrace statistics that the number of bytes transferred could change dramatically if you sorted your return data set. At the time I asked, and postponed answering, the question: “but how come the number of SQL*Net round trips has not changed ?”
A couple of weeks ago someone asked me if I had ever got around to answering this question – and I hadn’t. So I started by writing an answering comment, then decided it was getting a little long so transferred it to a separate blog note, and here it is.
We can start with the two sets of stats:

Statistics
----------------------------------------------------------
          4  recursive calls
          0  db block gets
        143  consistent gets
          0  physical reads
          0  redo size
     425479  bytes sent via SQL*Net to client
        494  bytes received via SQL*Net from client
         11  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
      10000  rows processed

Statistics
----------------------------------------------------------
          4  recursive calls
          0  db block gets
        133  consistent gets
          0  physical reads
          0  redo size
      79287  bytes sent via SQL*Net to client
        494  bytes received via SQL*Net from client
         11  SQL*Net roundtrips to/from client
          1  sorts (memory)
          0  sorts (disk)
      10000  rows processed

Basically, the answer comes from interpreting the names of the statistics correctly.
The “SQL*Net roundtrips to/from client” is the number of pairs of waits for “SQL*Net Message from client”/“SQL*Net Message to client” – which is controlled (in this example) very strongly by the array fetch size and the total number of rows (Note: we have arraysize = 1000 and rows returned = 10000 … the number of round trips is very close to 10,000 / 1,000.) This is exactly how the statistic is described in the SQL*Plus User’s Guide and Reference which says: “Total number of Oracle Net messages sent to and received from the client” – the trouble is, this description is easy to mis-understand.
If we enable extended SQL tracing (event 10046 / dbms_monitor) we would see that there is more activity going on than is reported by the autotrace statistics:

Here’s a sample of waits from the first query (retested on 11.2.0.2) with one blank line inserted for clarity:

WAIT #140199974133928: nam='SQL*Net message from client' ela= 319 driver id=1650815232 #bytes=1 p3=0 obj#=-40016366 tim=1370786699605359
WAIT #140199974133928: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-40016366 tim=1370786699605402
WAIT #140199974133928: nam='SQL*Net more data to client' ela= 34 driver id=1650815232 #bytes=8155 p3=0 obj#=-40016366 tim=1370786699605478
WAIT #140199974133928: nam='SQL*Net more data to client' ela= 4 driver id=1650815232 #bytes=8148 p3=0 obj#=-40016366 tim=1370786699605528
WAIT #140199974133928: nam='SQL*Net more data to client' ela= 3 driver id=1650815232 #bytes=8148 p3=0 obj#=-40016366 tim=1370786699605565
WAIT #140199974133928: nam='SQL*Net more data to client' ela= 3 driver id=1650815232 #bytes=8148 p3=0 obj#=-40016366 tim=1370786699605603
WAIT #140199974133928: nam='SQL*Net more data to client' ela= 3 driver id=1650815232 #bytes=8148 p3=0 obj#=-40016366 tim=1370786699605640
FETCH #140199974133928:c=0,e=262,p=0,cr=7,cu=0,mis=0,r=1000,dep=0,og=1,plh=3617692013,tim=1370786699605654

WAIT #140199974133928: nam='SQL*Net message from client' ela= 319 driver id=1650815232 #bytes=1 p3=0 obj#=-40016366 tim=1370786699605993
WAIT #140199974133928: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-40016366 tim=1370786699606024
WAIT #140199974133928: nam='SQL*Net more data to client' ela= 19 driver id=1650815232 #bytes=8155 p3=0 obj#=-40016366 tim=1370786699606082
WAIT #140199974133928: nam='SQL*Net more data to client' ela= 3 driver id=1650815232 #bytes=8148 p3=0 obj#=-40016366 tim=1370786699606127
WAIT #140199974133928: nam='SQL*Net more data to client' ela= 3 driver id=1650815232 #bytes=8148 p3=0 obj#=-40016366 tim=1370786699606163
WAIT #140199974133928: nam='SQL*Net more data to client' ela= 3 driver id=1650815232 #bytes=8148 p3=0 obj#=-40016366 tim=1370786699606199
WAIT #140199974133928: nam='SQL*Net more data to client' ela= 3 driver id=1650815232 #bytes=8148 p3=0 obj#=-40016366 tim=1370786699606234
FETCH #140199974133928:c=0,e=230,p=0,cr=7,cu=0,mis=0,r=1000,dep=0,og=1,plh=3617692013,tim=1370786699606247

And here’s the equivalent on the 2nd query:

WAIT #140199974133928: nam='SQL*Net message from client' ela= 1187 driver id=1650815232 #bytes=1 p3=0 obj#=-40016366 tim=1370786699689809
WAIT #140199974133928: nam='SQL*Net message to client' ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=-40016366 tim=1370786699689893
FETCH #140199974133928:c=0,e=540,p=0,cr=0,cu=0,mis=0,r=1000,dep=0,og=1,plh=2148421099,tim=1370786699690421

WAIT #140199974133928: nam='SQL*Net message from client' ela= 1096 driver id=1650815232 #bytes=1 p3=0 obj#=-40016366 tim=1370786699691585
WAIT #140199974133928: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=-40016366 tim=1370786699691666
FETCH #140199974133928:c=0,e=506,p=0,cr=0,cu=0,mis=0,r=999,dep=0,og=1,plh=2148421099,tim=1370786699692161

My session data unit (SDU) has defaulted to roughly 8KB and if you convert the driver id (1650815232) to hexadecimal you get 0×62657100, which you can recognise as BEQ, the local (bequeath) connection.
When there is little de-duplication available in the data order (first example) the 1,000 rows I fetch on each fetch call total about 48KB and I end up doing one “SQL*Net message to client” with five follow-up “SQL*Net more data to client”. (The bytes parameter for the “SQL*Net message to client” always shows 1 – Cary Millsap, I think, has pointed out that this is a long-standing error, so I’m assuming the call would be passing 8KB like all the other calls).
When I get maximum de-duplication in the data the entire 1,000 rows manages to compress down to less than the 8KB that’s available and all I see is the single “SQL*Net message to client”. with no calls for more data.
So – SQL*Net roundtrips isn’t measuring what you think – based on an informal reading of the description you and I might expect the first test to report far more round trips than the second, but that’s not the way that Oracle reports it, it’s literally counting the number of specific pairs of waits for “SQL*Net message to/from client” – the “more data” trips don’t get counted. As a result the same number of round-trips can report a hugely (and arbitrarily) different number of bytes.

Footnote:

I’ve only just noticed that I seem to be the only person that uses SQL*Plus. When I searched at tahiti.oracle.com to find the documented description of this statistics – I notice that the manual title was “SQL*Plus User’s Guide and Reference”; if there were more users it would be “SQL*Plus Users’ Guide and Reference” (check the apostrophe). Since I know that I use SQL*Plus that must mean no-one else does ;) I guess everyone else uses GUIs nowadays.



DIGITAL JUICE