Re: Surprising Performance Changes with Oracle 11.2.0.1 (Long Post)

From: Charles Hooper <hooperc2000_at_yahoo.com>
Date: Wed, 9 Sep 2009 17:12:12 -0700 (PDT)
Message-ID: <59ad9f5f-e7dd-40a9-b0bc-9289ad711231_at_j4g2000yqa.googlegroups.com>



On Sep 9, 5:48 am, "Gerard H. Pille" <ghpi..._at_hotmail.com> wrote:
> Hallo Charles,
>
> I'd like to see your statistics for this select:
>
> SELECT /*+ index (t1 ind_t1) */
>   ID,
>   DESCRIPTION
> FROM
>   sys.T1 t1
> WHERE
>   ID >= 9991
> /
>
> I suppose you were aware of the skew in the index, but how does this
> account for the difference in performance?
>
> On my old PC - with a new disk - the FTS takes 2 minutes, the IS 20
> minutes, selecting id between 1 and 400 via index takes over 3 hours.
>
> Kind regards,
>
> Gerard

Yes, there is a skew in the data - it should be more densely packed at each end of the range.

Here is a slightly modified version of the script you requested I run so that we are able to see the costs, and potentially some of the effects of an unset filesystemio_options parameter by executing the same query a second time:
set linesize 150
set pagesize 2000
ALTER SYSTEM FLUSH BUFFER_CACHE;
ALTER SYSTEM FLUSH SHARED_POOL;
SET ARRAYSIZE 100 spool /u01/app/oracle/results/filesystemio_options_unset.txt

SET AUTOTRACE TRACEONLY EXPLAIN
SELECT /*+ index (t1 ind_t1) */
  ID,
  DESCRIPTION
FROM
  T1 t1
WHERE
  ID >= 9991;

SET ARRAYSIZE 100
SET AUTOTRACE TRACEONLY STATISTICS SET TIMING ON SELECT /*+ index (t1 ind_t1) */
  ID,
  DESCRIPTION
FROM
  T1 t1
WHERE
  ID >= 9991;

SELECT /*+ index (t1 ind_t1) */
  ID,
  DESCRIPTION
FROM
  T1 t1
WHERE
  ID >= 9991;

spool off

This is the output:
Execution Plan



Plan hash value:
634656657
| Id  | Operation                   | Name   | Rows  | Bytes | Cost
(%CPU)| Time
|

| 0 | SELECT STATEMENT | | 100K| 5273K| 99458 (1)| 00:19:54
|
| 1 | TABLE ACCESS BY INDEX ROWID| T1 | 100K| 5273K| 99458 (1)| 00:19:54
|
|* 2 | INDEX RANGE SCAN | IND_T1 | 100K| | 212 (1)| 00:00:03
|

Predicate Information (identified by operation id):


   2 - access
("ID">=9991)

2847287 rows selected.

Elapsed: 00:05:04.91

Statistics


          1 recursive
calls

          0 db block
gets

    2568572 consistent
gets

    2540316 physical
reads

          0 redo
size
  173286364 bytes sent via SQL*Net to
client

     313716 bytes received via SQL*Net from client

      28474 SQL*Net roundtrips to/from
client

          0 sorts
(memory)

          0 sorts
(disk)

    2847287 rows
processed

2847287 rows selected.

Elapsed: 00:00:19.39

Statistics


          0 recursive
calls

          0 db block
gets

    2568572 consistent
gets

    2536953 physical
reads

          0 redo
size
  173286364 bytes sent via SQL*Net to
client

     313716 bytes received via SQL*Net from client

      28474 SQL*Net roundtrips to/from
client

          0 sorts
(memory)

          0 sorts
(disk)

    2847287 rows
processed

The first execution completed in 5 minutes and almost 5 seconds. The second execution completed in 19.39 seconds with a nearly identical value for physical block reads.

Charles Hooper
IT Manager/Oracle DBA
K&M Machine-Fabricating, Inc. Received on Wed Sep 09 2009 - 19:12:12 CDT

Original text of this message