Can anyone explain this huge increase in logical I./O....?

From: <mccmx_at_hotmail.com>
Date: 23 Oct 2006 08:02:50 -0700
Message-ID: <1161615770.624156.51920@i42g2000cwa.googlegroups.com>

Oracle 10.2.0.2 SE on Windows 2003

The following SQL runs against 2 different databases on 2 different servers. However it runs for 4 times longer on one of the DBs. tkprof shows that the explain plan is identical and the number of parse, execute, and fetch calls is identical. However the logical I/O count is drastically higher in the slower DB. Anyone have any ideas what is responsible for the huge increase in 'consistent reads' in the second DB below.

DB One (fast):

SELECT ROWID, PART_COUNT
FROM
 PS_TM_PEFF_GPQ WHERE BUSINESS_UNIT = :1 AND PRODUCTION_DT = :2 AND   SRG_CODE = :3 AND DEPTID = :4 AND PROCESS_CODE = :5 AND PART_NUM

• :6 AND PART_SFX_CD = :7 AND LINE_CODE = :8 AND CONV_SOURCE =
  'ALC'
  AND CONV_STATUS <> 'M'

call count cpu elapsed disk query current

    rows
------- ------ -------- ---------- ---------- ---------- ----------

---

Parse        0      0.00       0.00          0          0          0
       0
Execute 320277     13.93      13.61          0          0          0
       0
Fetch   638104     20.70      18.85         16    1613065          0

  317827
------- ------ -------- ---------- ---------- ---------- ----------

---

total 958381 34.64 32.46 16 1613065 0   317827

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 29

Rows Row Source Operation

-------  ---------------------------------------------------

 317827 TABLE ACCESS BY INDEX ROWID PS_TM_PEFF_GPQ (cr=1613065 pr=16 pw=0 time=14331876 us)
 317827 INDEX UNIQUE SCAN PS_TM_PEFF_GPQ (cr=1281108 pr=16 pw=0 time=8394762 us)(object id 13039)

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total

Waited

• Waited ----------

  ---

  cursor: pin S wait on X 10 0.01 0.09 SQL*Net message to client 638104 0.00 0.96 SQL*Net message from client 638104 0.01 69.23 latch: cache buffers chains 3 0.00 0.00 db file sequential read 16 0.11 0.18 cursor: pin S 6 0.00 0.00

  ---

DB Two (slow):

SELECT ROWID, PART_COUNT
FROM
 PS_TM_PEFF_GPQ WHERE BUSINESS_UNIT = :1 AND PRODUCTION_DT = :2 AND   SRG_CODE = :3 AND DEPTID = :4 AND PROCESS_CODE = :5 AND PART_NUM

• :6 AND PART_SFX_CD = :7 AND LINE_CODE = :8 AND CONV_SOURCE =
  'ALC'
  AND CONV_STATUS <> 'M'

call count cpu elapsed disk query current

    rows
------- ------ -------- ---------- ---------- ---------- ----------

---

Parse        0      0.00       0.00          0          0          0
       0
Execute 320277     16.21      15.97          0          0          0
       0
Fetch   638104    104.93     106.39         22   40083925          0

  317827
------- ------ -------- ---------- ---------- ---------- ----------

---

total 958381 121.15 122.37 22 40083925 0   317827

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 29

Rows Row Source Operation

-------  ---------------------------------------------------

 317827 TABLE ACCESS BY INDEX ROWID PS_TM_PEFF_GPQ (cr=40083925 pr=22 pw=0 time=102291805 us)
 317827 INDEX UNIQUE SCAN PS_TM_PEFF_GPQ (cr=1281108 pr=2 pw=0 time=10103556 us)(object id 13039)

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total

Waited

• Waited ----------

  ---

  cursor: pin S wait on X 2 0.01 0.01 SQL*Net message to client 638104 0.01 0.97 SQL*Net message from client 638104 0.04 112.61 db file sequential read 22 0.03 0.05 latch: cache buffers chains 2957 0.00 0.05 buffer busy waits 11 0.00 0.00 cursor: pin S 2 0.00 0.00 latch free 1 0.00 0.00

  ---

I have confirmed that the non-default init.ora parameters are identical

The row counts are identical and the block counts of the table and the clustering factor of the index are very close in both DBs:

DB One (fast):

select blocks, empty_blocks, avg_row_len from user_tables where table_name =
'PS_TM_PEFF_GPQ';
    BLOCKS EMPTY_BLOCKS AVG_ROW_LEN
---------- ------------ -----------

    100382 0 52

select BLEVEL, LEAF_BLOCKS, AVG_LEAF_BLOCKS_PER_KEY, AVG_DATA_BLOCKS_PER_KEY, CLUSTERING_FACTOR from user_indexes where table_name = 'PS_TM_PEFF_GPQ'

BLEVEL LEAF_BLOCKS AVG_LEAF_BLOCKS_PER_KEY AVG_DATA_BLOCKS_PER_KEY CLUSTERING_FACTOR

------ ----------- ----------------------- -----------------------
-----------------
     3       88707                       1                       1
     3700235
     3      123732                       1                       1

    10069887

DB Two (slow):

select blocks, empty_blocks, avg_row_len from user_tables where table_name =
'PS_TM_PEFF_GPQ';
    BLOCKS EMPTY_BLOCKS AVG_ROW_LEN
---------- ------------ -----------

    101146 0 52

select BLEVEL, LEAF_BLOCKS, AVG_LEAF_BLOCKS_PER_KEY, AVG_DATA_BLOCKS_PER_KEY, CLUSTERING_FACTOR from user_indexes where table_name = 'PS_TM_PEFF_GPQ'

BLEVEL LEAF_BLOCKS AVG_LEAF_BLOCKS_PER_KEY AVG_DATA_BLOCKS_PER_KEY CLUSTERING_FACTOR

------ ----------- ----------------------- -----------------------
-----------------
     3      132011                       1                       1
     4174537
     3      125284                       1                       1

    10603144

Any help appreciated...

Matt Received on Mon Oct 23 2006 - 10:02:50 CDT