RE: Increasing row retrieving speed via net8

From: Mark W. Farnham <mwf_at_rsiz.com>
Date: Wed, 11 Apr 2012 15:16:33 -0400
Message-ID: <00a001cd1817$9c2a6170$d47f2450$_at_rsiz.com>



It seems to me that running 2, 3, ..., n sessions in parallel and drawing the curve of total throughput would tell you whether you have remaining actual headroom in the network bandwidth.

You might want to make an actual copy of something as your rowsource so you can get it clean in cache or at least be sure you're not waiting for concurrency issues or block cleanouts or undo references or anything else that might inject elapsed time apart from the thing you are intending to test.

"List Price" bandwidth, actual total bandwidth, and currently available headroom can be very different things.

Good luck,

mwf

-----Original Message-----

From: oracle-l-bounce_at_freelists.org [mailto:oracle-l-bounce_at_freelists.org] On Behalf Of GG Sent: Wednesday, April 11, 2012 2:31 PM
To: oracle-l_at_freelists.org
Subject: Increasing row retrieving speed via net8

Hi,
  I'm doing large table processing (row fetching) via Net8 , remote client using JDBC oracle client . Did some testing using snapper and two VMs with Oracle 11.2.0.2 . Got table T with 5M rows avg row length is 104 (its CATS from DBA_SOURCE and doing simple select * from t) . First I used BEQ (local connection :)) protocol as a reference :

SQL> _at_snapper all 5 1 145
Sampling SID 145 with interval 5 seconds, taking 1 snapshots... setting stats to all due to option = all

     SID, USERNAME  , TYPE, 
STATISTIC                                                 ,         
DELTA,     HDELTA, HDELTA/SEC,    %TIME, GRAPH

----------------------------------------------------------------------------------------------------------------------------------------------------
145, GG , STAT, user calls , 1319, 1.32k, 263.8, 145, GG , STAT, session logical reads , 23498, 23.5k, 4.7k, 145, GG , STAT, CPU used when call started , 27, 27, 5.4, 145, GG , STAT, CPU used by this session , 27, 27, 5.4, 145, GG , STAT, DB time , 43, 43, 8.6, 145, GG , STAT, user I/O wait time , 2, 2, .4, 145, GG , STAT, non-idle wait time , 15, 15, 3, 145, GG , STAT, non-idle wait count , 10091, 10.09k, 2.02k, 145, GG , STAT, physical read total IO requests , 698, 698, 139.6, 145, GG , STAT, physical read total multi block requests , 687, 687, 137.4, 145, GG , STAT, physical read total bytes , 91127808, 91.13M, 18.23M, 145, GG , STAT, cell physical IO interconnect bytes , 91127808, 91.13M, 18.23M, 145, GG , STAT, consistent gets , 23498, 23.5k, 4.7k, 145, GG , STAT, consistent gets from cache , 11075, 11.08k, 2.22k, 145, GG , STAT, consistent gets - examination , 11075, 11.08k, 2.22k, 145, GG , STAT, consistent gets direct , 12423, 12.42k, 2.48k, 145, GG , STAT, physical reads , 11124, 11.12k, 2.22k, 145, GG , STAT, physical reads direct , 11124, 11.12k, 2.22k, 145, GG , STAT, physical read IO requests , 698, 698, 139.6, 145, GG , STAT, physical read bytes , 91127808, 91.13M, 18.23M, 145, GG , STAT, Number of read IOs issued , 698, 698, 139.6, 145, GG , STAT, no work - consistent read gets , 1348, 1.35k, 269.6, 145, GG , STAT, cleanouts only - consistent read gets , 11073, 11.07k, 2.21k, 145, GG , STAT, immediate (CR) block cleanout applications , 11073, 11.07k, 2.21k, 145, GG , STAT, commit txn count during cleanout , 11073, 11.07k, 2.21k, 145, GG , STAT, cleanout - number of ktugct calls , 11073, 11.07k, 2.21k, 145, GG , STAT, table scan rows gotten , 659500, 659.5k, 131.9k, 145, GG , STAT, table scan blocks gotten , 12421, 12.42k, 2.48k, 145, GG , STAT, buffer is not pinned count , 12366, 12.37k, 2.47k, 145, GG , STAT, bytes sent via SQL*Net to client , 70786316, 70.79M, 14.16M, 145, GG , STAT, bytes received via SQL*Net from client , 26420, 26.42k, 5.28k, 145, GG , STAT, SQL*Net roundtrips to/from client , 1321, 1.32k, 264.2, 145, GG , TIME, DB CPU , 334948, 334.95ms, 66.99ms, 6.7%, |_at_ | 145, GG , TIME, sql execute elapsed time , 354361, 354.36ms, 70.87ms, 7.1%, |_at_ | 145, GG , TIME, DB time , 388813, 388.81ms, 77.76ms, 7.8%, |_at_ | 145, GG , WAIT, direct path read , 20519, 20.52ms, 4.1ms, .4%, | | 145, GG , WAIT, SQL*Net message to client , 7278, 7.28ms, 1.46ms, .1%, | | 145, GG , WAIT, SQL*Net more data to client , 120134, 120.13ms, 24.03ms, 2.4%, |_at_ | 145, GG , WAIT, SQL*Net message from client , 4023802, 4.02s,
804.76ms, 80.5%, |_at_@@@@@@@ |
-- End of Stats snap 1, end=2012-04-11 09:18:15, seconds=5

Active% | SQL_ID          | EVENT                               | WAIT_CLASS

---------------------------------------------------------------------------------
9% | 89km4qj1thh13 | SQL*Net more data to client | Network 5% | 89km4qj1thh13 | ON CPU | ON CPU
  • End of ASH snap 1, end=2012-04-11 09:18:15, seconds=5, samples_taken=43

so if I interpreting this correctly we can fetch like:

      131.9k rows per sec which is good

Now switching to Net8 with arraysize 15:

SQL> _at_snapper all 5 1 149
Sampling SID 149 with interval 5 seconds, taking 1 snapshots... setting stats to all due to option = all

     SID, USERNAME  , TYPE, 
STATISTIC                                                 ,         
DELTA,     HDELTA, HDELTA/SEC,    %TIME, GRAPH

----------------------------------------------------------------------------------------------------------------------------------------------------
149, GG , STAT, user calls , 12036, 12.04k, 2.41k, 149, GG , STAT, session logical reads , 18097, 18.1k, 3.62k, 149, GG , STAT, CPU used when call started , 67, 67, 13.4, 149, GG , STAT, CPU used by this session , 67, 67, 13.4, 149, GG , STAT, DB time , 67, 67, 13.4, 149, GG , STAT, user I/O wait time , 1, 1, .2, 149, GG , STAT, non-idle wait time , 26, 26, 5.2, 149, GG , STAT, non-idle wait count , 12923, 12.92k, 2.58k, 149, GG , STAT, physical read total IO requests , 214, 214, 42.8, 149, GG , STAT, physical read total multi block requests , 211, 211, 42.2, 149, GG , STAT, physical read total bytes , 27951104, 27.95M, 5.59M, 149, GG , STAT, cell physical IO interconnect bytes , 27951104, 27.95M, 5.59M, 149, GG , STAT, consistent gets , 18098, 18.1k, 3.62k, 149, GG , STAT, consistent gets from cache , 2843, 2.84k, 568.6, 149, GG , STAT, consistent gets - examination , 2843, 2.84k, 568.6, 149, GG , STAT, consistent gets direct , 15254, 15.25k, 3.05k, 149, GG , STAT, physical reads , 3428, 3.43k, 685.6, 149, GG , STAT, physical reads direct , 3428, 3.43k, 685.6, 149, GG , STAT, physical read IO requests , 215, 215, 43, 149, GG , STAT, physical read bytes , 28082176, 28.08M, 5.62M, 149, GG , STAT, Number of read IOs issued , 216, 216, 43.2, 149, GG , STAT, no work - consistent read gets , 12387, 12.39k, 2.48k, 149, GG , STAT, cleanouts only - consistent read gets , 2847, 2.85k, 569.4, 149, GG , STAT, immediate (CR) block cleanout applications , 2848, 2.85k, 569.6, 149, GG , STAT, commit txn count during cleanout , 2848, 2.85k, 569.6, 149, GG , STAT, cleanout - number of ktugct calls , 2848, 2.85k, 569.6, 149, GG , STAT, table scan rows gotten , 180270, 180.27k, 36.05k, 149, GG , STAT, table scan blocks gotten , 15225, 15.23k, 3.05k, 149, GG , STAT, buffer is not pinned count , 15147, 15.15k, 3.03k, 149, GG , STAT, bytes sent via SQL*Net to client , 22665295, 22.67M, 4.53M, 149, GG , STAT, bytes received via SQL*Net from client , 238900, 238.9k, 47.78k, 149, GG , STAT, SQL*Net roundtrips to/from client , 11944, 11.94k, 2.39k, 149, GG , TIME, DB CPU , 1566761, 1.57s, 313.35ms, 31.3%, |_at_@@@ | 149, GG , TIME, sql execute elapsed time , 494193, 494.19ms, 98.84ms, 9.9%, |_at_ | 149, GG , TIME, DB time , 1566724, 1.57s, 313.34ms, 31.3%, |_at_@@@ | 149, GG , WAIT, direct path read , 9762, 9.76ms, 1.95ms, .2%, | | 149, GG , WAIT, SQL*Net message to client , 16290, 16.29ms, 3.26ms, .3%, | | 149, GG , WAIT, SQL*Net more data to client , 231066, 231.07ms, 46.21ms, 4.6%, |_at_ | 149, GG , WAIT, SQL*Net message from client , 3640845, 3.64s,
728.17ms, 72.8%, |_at_@@@@@@@ |
-- End of Stats snap 1, end=2012-04-11 09:36:35, seconds=5

Active% | SQL_ID          | EVENT                               | WAIT_CLASS

---------------------------------------------------------------------------------
7% | 89km4qj1thh13 | ON CPU | ON CPU
  • End of ASH snap 1, end=2012-04-11 09:36:35, seconds=5, samples_taken=42

here we can have like 36.05k rows per seconds .

Now with fetch size 500 I can do:

SQL> _at_snapper all 5 1 149
Sampling SID 149 with interval 5 seconds, taking 1 snapshots... setting stats to all due to option = all

     SID, USERNAME  , TYPE, 
STATISTIC                                                 ,         
DELTA,     HDELTA, HDELTA/SEC,    %TIME, GRAPH

----------------------------------------------------------------------------------------------------------------------------------------------------
149, GG , STAT, user calls , 726, 726, 145.2, 149, GG , STAT, session logical reads , 8640, 8.64k, 1.73k, 149, GG , STAT, CPU used when call started , 183, 183, 36.6, 149, GG , STAT, CPU used by this session , 183, 183, 36.6, 149, GG , STAT, DB time , 174, 174, 34.8, 149, GG , STAT, user I/O wait time , 3, 3, .6, 149, GG , STAT, non-idle wait time , 170, 170, 34, 149, GG , STAT, non-idle wait count , 5925, 5.93k, 1.19k, 149, GG , STAT, physical read total IO requests , 434, 434, 86.8, 149, GG , STAT, physical read total multi block requests , 414, 414, 82.8, 149, GG , STAT, physical read total bytes , 56483840, 56.48M, 11.3M, 149, GG , STAT, cell physical IO interconnect bytes , 56483840, 56.48M, 11.3M, 149, GG , STAT, consistent gets , 8640, 8.64k, 1.73k, 149, GG , STAT, consistent gets from cache , 1006, 1.01k, 201.2, 149, GG , STAT, consistent gets - examination , 1006, 1.01k, 201.2, 149, GG , STAT, consistent gets direct , 7634, 7.63k, 1.53k, 149, GG , STAT, physical reads , 6911, 6.91k, 1.38k, 149, GG , STAT, physical reads direct , 6911, 6.91k, 1.38k, 149, GG , STAT, physical read IO requests , 435, 435, 87, 149, GG , STAT, physical read bytes , 56614912, 56.61M, 11.32M, 149, GG , STAT, Number of read IOs issued , 436, 436, 87.2, 149, GG , STAT, no work - consistent read gets , 6617, 6.62k, 1.32k, 149, GG , STAT, cleanouts only - consistent read gets , 1016, 1.02k, 203.2, 149, GG , STAT, immediate (CR) block cleanout applications , 1016, 1.02k, 203.2, 149, GG , STAT, commit txn count during cleanout , 1016, 1.02k, 203.2, 149, GG , STAT, cleanout - number of ktugct calls , 1016, 1.02k, 203.2, 149, GG , STAT, table scan rows gotten , 363000, 363k, 72.6k, 149, GG , STAT, table scan blocks gotten , 7630, 7.63k, 1.53k, 149, GG , STAT, buffer is not pinned count , 7630, 7.63k, 1.53k, 149, GG , STAT, bytes sent via SQL*Net to client , 41730447, 41.73M, 8.35M, 149, GG , STAT, bytes received via SQL*Net from client , 14500, 14.5k, 2.9k, 149, GG , STAT, SQL*Net roundtrips to/from client , 726, 726, 145.2, 149, GG , TIME, DB CPU , 2018693, 2.02s, 403.74ms, 40.4%, |_at_@@@ | 149, GG , TIME, sql execute elapsed time , 1853871, 1.85s, 370.77ms, 37.1%, |_at_@@@ | 149, GG , TIME, DB time , 2018383, 2.02s, 403.68ms, 40.4%, |_at_@@@ | 149, GG , WAIT, direct path read , 25985, 25.99ms, 5.2ms, .5%, |_at_ | 149, GG , WAIT, SQL*Net message to client , 2854, 2.85ms, 570.8us, .1%, | | 149, GG , WAIT, SQL*Net more data to client , 1674304, 1.67s, 334.86ms, 33.5%, |_at_@@@ | 149, GG , WAIT, SQL*Net message from client , 2222786, 2.22s, 444.56ms, 44.5%, |_at_@@@@ |

-- End of Stats snap 1, end=2012-04-11 09:31:06, seconds=5

Active% | SQL_ID          | EVENT                               | WAIT_CLASS

---------------------------------------------------------------------------------
30% | 89km4qj1thh13 | SQL*Net more data to client | Network 3% | 89km4qj1thh13 | ON CPU | ON CPU
  • End of ASH snap 1, end=2012-04-11 09:31:06, seconds=5, samples_taken=40

72,6k rows fetched per fetch .

Is there anything to do I can go further with Net8 ? I mean SDU in 11.2.0.2 defaults to 8k which seems ok . Considering 100Mbit ethernet speed , I can have like 10Mbytes/per sec so with 1GB table i need ~ 100 sec to transfer that . So feels like not on the edge yet .

Any ideas ?
Regards
GregG

--

http://www.freelists.org/webpage/oracle-l

--

http://www.freelists.org/webpage/oracle-l Received on Wed Apr 11 2012 - 14:16:33 CDT

Original text of this message