Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Query executes slower after indexes are created and dbms_stats compute is used

I have a table with 1.5 million rows. I run a query which fetches records having non repeating values in a column. I am observing a behaviour in which after creating indexes the performance of the query degrades. I also used dbms_stats with 100% estimate percentage(compute mode) to gather statistics so that oracle 11g CBO makes a more informed decision for the query plan, but it doesnt improve the query execution time.

 SQL> desc tab3;
 Name                 Null?    Type
 ----------------------------------------------
 COL1                          NUMBER(38)
 COL2                          VARCHAR2(100)
 COL3                          VARCHAR2(36)
 COL4                          VARCHAR2(36)
 COL5                          VARCHAR2(4000)
 COL6                          VARCHAR2(4000)
 MEASURE_0                     VARCHAR2(4000)
 MEASURE_1                     VARCHAR2(4000)
 MEASURE_2                     VARCHAR2(4000)
 MEASURE_3                     VARCHAR2(4000)
 MEASURE_4                     VARCHAR2(4000)
 MEASURE_5                     VARCHAR2(4000)
 MEASURE_6                     VARCHAR2(4000)
 MEASURE_7                     VARCHAR2(4000)
 MEASURE_8                     VARCHAR2(4000)
 MEASURE_9                     VARCHAR2(4000)

The column measure_0 has 0.4 million unique values.

SQL> select count(*) from (select measure_0 from tab3 group by measure_0 having count(*) = 1) abc;

  COUNT(*)
----------
    403664

The following is the query with the execution plan, please note there are no indexes on the table.

SQL> set autotrace traceonly;

SQL> SELECT * FROM (
  2     SELECT
  3             (ROWNUM -1) AS COL1,
  4             ft.COL1         AS OLD_COL1,
  5             ft.COL2,
  6             ft.COL3,
  7             ft.COL4,
  8             ft.COL5,
  9             ft.COL6,
 10             ft.MEASURE_0,
 11             ft.MEASURE_1,
 12             ft.MEASURE_2,
 13             ft.MEASURE_3,
 14             ft.MEASURE_4,
 15             ft.MEASURE_5,
 16             ft.MEASURE_6,
 17             ft.MEASURE_7,
 18             ft.MEASURE_8,
 19             ft.MEASURE_9
 20     FROM tab3 ft
 21     WHERE MEASURE_0 IN
 22      (
 23             SELECT MEASURE_0
 24             FROM tab3
 25             GROUP BY MEASURE_0
 26             HAVING COUNT(*) = 1
 27      )
 28  ) ABC WHERE COL1 >= 0 AND COL1 <=449;

450 rows selected.

Elapsed: 00:00:01.90

Execution Plan
----------------------------------------------------------
Plan hash value: 3115757351

------------------------------------------------------------------------------------
| Id  | Operation               | Name     | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT        |          |  1243 |    28M|   717K  (1)| 02:23:29 |
|*  1 |  VIEW                   |          |  1243 |    28M|   717K  (1)| 02:23:29 |
|   2 |   COUNT                 |          |       |       |            |          |
|*  3 |    HASH JOIN            |          |  1243 |    30M|   717K  (1)| 02:23:29 |
|   4 |     VIEW                | VW_NSO_1 |  1686K|  3219M|  6274   (2)| 00:01:16 |
|*  5 |      FILTER             |          |       |       |            |          |
|   6 |       HASH GROUP BY     |          |     1 |  3219M|  6274   (2)| 00:01:16 |
|   7 |        TABLE ACCESS FULL| TAB3     |  1686K|  3219M|  6196   (1)| 00:01:15 |
|   8 |     TABLE ACCESS FULL   | TAB3     |  1686K|    37G|  6211   (1)| 00:01:15 |
------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter("COL1">=0 AND "COL1"<=449)
   3 - access("MEASURE_0"="MEASURE_0")
   5 - filter(COUNT(*)=1)

Note
-----
   - dynamic sampling used for this statement (level=2)


Statistics
----------------------------------------------------------
        354  recursive calls
          0  db block gets
      46518  consistent gets
      45122  physical reads
          0  redo size
      43972  bytes sent via SQL*Net to client
        715  bytes received via SQL*Net from client
         31  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
        450  rows processed

The query takes up 1.90 seconds. If I run the query again it takes 1.66 seconds. Why does it take more time in the first run?

In order to speed it up I created indexes on the two columns used in the query.

SQL> create index ind_tab3_orgid on tab3(COL1);

Index created.

Elapsed: 00:00:01.68
SQL> create index ind_tab3_msr_0 on tab3(measure_0);

Index created.

Elapsed: 00:00:01.83

When I fired the query after this for the first time it took a whooping 21 seconds to come back. Whereas subsequent runs bought it to 2.9 seconds. Why does oracle take so much time in the first run, is it warming up or something.. baffles me!

This is the plan when it takes 2.9 seconds-

450 rows selected.

Elapsed: 00:00:02.92

Execution Plan
----------------------------------------------------------
Plan hash value: 240271480

-------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name           | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |                |  1243 |    28M|   711K  (1)| 02:22:15 |
|*  1 |  VIEW                          |                |  1243 |    28M|   711K  (1)| 02:22:15 |
|   2 |   COUNT                        |                |       |       |            |          |
|   3 |    NESTED LOOPS                |                |       |       |            |          |
|   4 |     NESTED LOOPS               |                |  1243 |    30M|   711K  (1)| 02:22:15 |
|   5 |      VIEW                      | VW_NSO_1       |  1686K|  3219M|  6274   (2)| 00:01:16 |
|*  6 |       FILTER                   |                |       |       |            |          |
|   7 |        HASH GROUP BY           |                |     1 |  3219M|  6274   (2)| 00:01:16 |
|   8 |         TABLE ACCESS FULL      | TAB3           |  1686K|  3219M|  6196   (1)| 00:01:15 |
|*  9 |      INDEX RANGE SCAN          | IND_TAB3_MSR_0 |  1243 |       |     2   (0)| 00:00:01 |
|  10 |     TABLE ACCESS BY INDEX ROWID| TAB3           |  1243 |    28M|    44   (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter("COL1">=0 AND "COL1"<=449)
   6 - filter(COUNT(*)=1)
   9 - access("MEASURE_0"="MEASURE_0")

Note
-----
   - dynamic sampling used for this statement (level=2)


Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
     660054  consistent gets
      22561  physical reads
          0  redo size
      44358  bytes sent via SQL*Net to client
        715  bytes received via SQL*Net from client
         31  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
        450  rows processed

I was expecting the time to be lower than when the table was non indexed. Why does the indexed version of the table takes more time to fetch the results than the non indexed version? If I am not wrong it is the TABLE ACCESS BY INDEX ROWID that is taking up time. Can I enforce oracle to use TABLE ACCESS FULL?

I then gathered statistics on the table so that CBO improves the plan with compute option. So now the statistics would be accurate.

SQL> EXECUTE dbms_stats.gather_table_stats (ownname=>'EQUBE67DP', tabname=>'TAB3',estimate_percent=>null,cascade=>true);

PL/SQL procedure successfully completed.

Elapsed: 00:01:02.47
SQL> set autotrace off;
SQL> select COLUMN_NAME,NUM_DISTINCT,SAMPLE_SIZE,HISTOGRAM,LAST_ANALYZED from dba_tab_cols where table_name = 'TAB3' ;

COLUMN_NAME                    NUM_DISTINCT SAMPLE_SIZE HISTOGRAM       LAST_ANALYZED
------------------------------ ------------ ----------- --------------- ---------
COL1                                1502257     1502257 NONE            27-JUN-12
COL2                                      0             NONE            27-JUN-12
COL3                                      1     1502257 NONE            27-JUN-12
COL4                                      0             NONE            27-JUN-12
COL5                                1502257     1502257 NONE            27-JUN-12
COL6                                1502257     1502257 NONE            27-JUN-12
MEASURE_0                            405609     1502257 HEIGHT BALANCED 27-JUN-12
MEASURE_1                            128570     1502257 NONE            27-JUN-12
MEASURE_2                           1502257     1502257 NONE            27-JUN-12
MEASURE_3                            185657     1502257 NONE            27-JUN-12
MEASURE_4                               901     1502257 NONE            27-JUN-12
MEASURE_5                                17     1502257 NONE            27-JUN-12
MEASURE_6                              2202     1502257 NONE            27-JUN-12
MEASURE_7                              2193     1502257 NONE            27-JUN-12
MEASURE_8                                21     1502257 NONE            27-JUN-12
MEASURE_9                             27263     1502257 NONE            27-JUN-12

I again ran the query

450 rows selected.

Elapsed: 00:00:02.95

Execution Plan
----------------------------------------------------------
Plan hash value: 240271480

-------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name           | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |                |    31M|   718G|  8046   (2)| 00:01:37 |
|*  1 |  VIEW                          |                |    31M|   718G|  8046   (2)| 00:01:37 |
|   2 |   COUNT                        |                |       |       |            |          |
|   3 |    NESTED LOOPS                |                |       |       |            |          |
|   4 |     NESTED LOOPS               |                |    31M|    62G|  8046   (2)| 00:01:37 |
|   5 |      VIEW                      | VW_NSO_1       |  4057 |  7931K|  6263   (2)| 00:01:16 |
|*  6 |       FILTER                   |                |       |       |            |          |
|   7 |        HASH GROUP BY           |                |     1 | 20285 |  6263   (2)| 00:01:16 |
|   8 |         TABLE ACCESS FULL      | TAB3           |  1502K|  7335K|  6193   (1)| 00:01:15 |
|*  9 |      INDEX RANGE SCAN          | IND_TAB3_MSR_0 |     4 |       |     2   (0)| 00:00:01 |
|  10 |     TABLE ACCESS BY INDEX ROWID| TAB3           |   779K|    75M|     3   (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - filter("COL1">=0 AND "COL1"<=449)
   6 - filter(COUNT(*)=1)
   9 - access("MEASURE_0"="MEASURE_0")


Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
     660054  consistent gets
      22561  physical reads
          0  redo size
      44358  bytes sent via SQL*Net to client
        715  bytes received via SQL*Net from client
         31  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
        450  rows processed

This time the query came back in 2.9 seconds (sometimes it took 3.9 seconds too).

My goal is to minimize the query execution time as much as possible. But after adding indexes or after computing statistics the query time just kept increasing. Why is this happening and how can I improve even by keeping the indexes?

like image 579
rirhs Avatar asked Jun 27 '12 15:06

rirhs


2 Answers

First of all, let me quote Tom Kyte:

just keep saying to yourself over and over

"full scans are not evil, indexes are not good"
"full scans are not evil, indexes are not good"
"full scans are not evil, indexes are not good"
"full scans are not evil, indexes are not good"
"full scans are not evil, indexes are not good"
"full scans are not evil, indexes are not good"

Indexes will not always improve performance, they are not the magical silver bullet (as if such a thing ever existed :)

Now you're asking why it takes longer with your index. The answer is pretty simple:

  • with the full table scan: 46518 consistent gets
  • with your index: 660054 consistent gets

In other words: Oracle perform more read operations with your index than with the full table scan. This happens because:

  1. FULL TABLE SCAN reads are bulk operations (many blocks at a time) and are therefore an efficient way to read lots of data
  2. sometimes when you read from an index you end up reading the exact same data block more than once.

As to why the optimizer chose to use this obviously non-efficient index, this is because even with esimate_percent=100 and full histograms (which you have collected on the MEASURE_0 column), some data distribution still can not be reliably expressed by the simple analysis of the optimizer. In particular, cross-column and cross-table dependency is not well-understood by the analyzer. This leads to wrong estimates, which lead to poor plan choice.

Edit: it seems the working hypothesis of the CBO are not working at all for this self-join (your last query expects 31 million rows whereas only 450 are selected !). This is quite puzzling since the table has only 1.5 M rows. What version of Oracle are you using?

I think you will find that you can remove the self-join and therefore improve query performance with analytics:

SELECT * FROM (
   SELECT (ROWNUM -1) AS COL1, ABC.*
     FROM (
      SELECT
              ft.COL1 AS OLD_COL1,
              [...],
              COUNT(*) OVER (PARTITION BY MEASURE_O) nb_0
      FROM tab3 ft
      ) ABC 
    WHERE nb_0 = 1
      AND ROWNUM - 1 <= 449
   ) v
 WHERE COL1 >= 0;

You were also asking why the first time a query is run takes more time in general. This is because there are caches at work. On the database level there is the SGA where all blocks are first copied from disk and then can be read multiple times (the first time a block is queried is always a physical read). Then some systems also have an independent system cache that will return data faster if it has been read recently.

For further reading:

  • an explication of a data discrepancy that can lead to wrong estimates and a solution involving SQL profiles.
like image 171
Vincent Malgrat Avatar answered Oct 30 '22 11:10

Vincent Malgrat


How does this code perform?

SELECT ROWNUM - 1      AS col1
,      ft.col1         AS old_col1
,      ft.col2
,      ft.col3
,      ft.col4
,      ft.col5
,      ft.col6
,      ft.measure_0
,      ft.measure_1
,      ft.measure_2
,      ft.measure_3
,      ft.measure_4
,      ft.measure_5
,      ft.measure_6
,      ft.measure_7
,      ft.measure_8
,      ft.measure_9
FROM   tab3 ft
WHERE  NOT EXISTS (SELECT NULL
                   FROM   tab3   ft_prime
                   WHERE  ft_prime.measure_0 = ft.measure_0
                   AND    ft_prime.ROWID <> ft.ROWID)
AND    ROWNUM <= 450;
like image 25
Tebbe Avatar answered Oct 30 '22 10:10

Tebbe