Unexpected Logical I/O count

From: Matt <mccmx_at_hotmail.com>
Date: 6 Oct 2004 00:13:30 -0700
Message-ID: <cfee5bcf.0410052313.4255fb4c@posting.google.com>

8.1.7.2.1 EE on HP-UX 11.

I have a SQL statement which I suspect is taking longer than it should.

It executes for 4/5 seconds and visits over 500,000 logical blocks.

I copied the tables and view definition into an 8.1.7.4.1 database on NT and found that the same SQL statement executed in 2 seconds and only visited half the number of blocks despite using the same plan and using the same block size and all other init.ora parameters (I actually used the same init.ora file).

I've checked the number of blocks in all of the objects (tables and indexes) in the 2 databases and they are almost exactly the same.

Anyone have any idea why this is the case. My first instinct was that the extra block visits were for read consistency but a count from v$transaction releaved that there were no active transactions at the time of the queries. Also the 500,000+ block count is consistently repeateable.

What could account for the extra bock visits when the segments are made up of the same number of rows and blocks and the optimizer choses exactly the same plan..? (The elapsed time is almost totally CPU related - i.e. no waits.)

Check out the 2 tkprof outputs:

Slow one (8.1.7.2.1 - HP-UX):

select count(*) from ps_tm_peff_v_cceh
where business_unit = 'TMUK'
and tm_date between '01-APR-04' and '30-APR-04'

call     count       cpu    elapsed       disk      query    current  
     rows

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

---

Parse        1      0.01       0.01          0          0          0  
        0
Execute      1      0.00       0.00          0          0          0  
        0
Fetch        2      4.34       4.35          0     591168          0  
        1

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

---

total        4      4.35       4.36          0     591168          0  
        1

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 18 (SYSADM)

Rows Row Source Operation

-------  ---------------------------------------------------
      1  SORT AGGREGATE 

  12894 VIEW PS_TM_PEFF_V_CCEH
  12894 SORT GROUP BY

 154410     FILTER 
 202782      NESTED LOOPS OUTER 
 154656       TABLE ACCESS BY INDEX ROWID PS_TM_PEFF_GPQCAL 
 154656        INDEX RANGE SCAN (object id 6596)
 185624       INDEX RANGE SCAN (object id 6554)


Rows     Execution Plan
-------  ---------------------------------------------------
      0  SELECT STATEMENT   GOAL: CHOOSE
      1   SORT (AGGREGATE)
  12894    VIEW OF 'PS_TM_PEFF_V_CCEH'
  12894     SORT (GROUP BY)
 154410      FILTER
 202782       NESTED LOOPS (OUTER)
 154656        TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                   'PS_TM_PEFF_GPQCAL'
 154656         INDEX   GOAL: ANALYZED (RANGE SCAN) OF 
                    'PS_TM_PEFF_GPQCAL' (UNIQUE)
 185624        INDEX (RANGE SCAN) OF 'PSATM_PEFF_BNCHMRK' (UNIQUE)

Fast one (8.1.7.4.1 - NT):

select count(*) from ps_tm_peff_v_cceh
where business_unit = 'TMUK'
and tm_date between '01-APR-04' and '30-APR-04'

call     count       cpu    elapsed       disk      query    current  
     rows

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

---

Parse        1      0.17       0.18          0          0          0  
        0
Execute      1      0.00       0.00          0          0          0  
        0
Fetch        2      2.22       2.23          0     271015          0  
        1

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

---

total        4      2.39       2.41          0     271015          0  
        1

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 18 (PEFF)

Rows Row Source Operation

-------  ---------------------------------------------------
      1  SORT AGGREGATE 

  12744 VIEW PS_TM_PEFF_V_CCEH
  12744 SORT GROUP BY

 154260     FILTER 
 202532      NESTED LOOPS OUTER 
 154506       TABLE ACCESS BY INDEX ROWID PS_TM_PEFF_GPQCAL 
 154506        INDEX RANGE SCAN (object id 2982)
 185524       INDEX RANGE SCAN (object id 2980)


Rows     Execution Plan
-------  ---------------------------------------------------
      0  SELECT STATEMENT   GOAL: CHOOSE
      1   SORT (AGGREGATE)
  12744    VIEW OF 'PS_TM_PEFF_V_CCEH'
  12744     SORT (GROUP BY)
 154260      FILTER
 202532       NESTED LOOPS (OUTER)
 154506        TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                   'PS_TM_PEFF_GPQCAL'
 154506         INDEX   GOAL: ANALYZED (RANGE SCAN) OF 
                    'PS_TM_PEFF_GPQCAL' (UNIQUE)
 185524        INDEX   GOAL: ANALYZED (RANGE SCAN) OF 
                   'PSATM_PEFF_BNCHMRK' (UNIQUE)

Thanks,

Matt Received on Wed Oct 06 2004 - 02:13:30 CDT