J'ai constaté cette semaine sur une des bases sur lesquelles je travaille que la requête suivante s'est mis à bien tourner du jour au lendemain:
On peut constater cela en regardant les stats au niveau de l'AWR:
Je trouve ça complètement illogique surtout lorsque l'on sait que les index range scan par rapport aux index unique scan entrainent un surcoût lié notamment au nombre de latchs plus importants générés et au fait qu'en cas d'index range scan oracle doit checker l'entrée d'index suivant (juste au cas où) car cette opération par définition peut retourner plusieurs lignes alors qu'avec un index unqiue scan Oracle est sûr de n'avoir au plus qu'une seule entrée d'index correspondante.
Je vous invite à lire l'article de Richard FOOTE sur ce sujet.
Pour en revenir à mon cas et pour confirmer mon hypothèse de départ sur le nombre de colonnes, j'ai (sur les conseils de mon ami Guy-Georges DROGBA) généré de nouveau le plan après avoir cette fois désactivé le CPU costing:
Ah! cette fois lorsque le CPU costing est désactivé c'est bien l'index unique qui est pris en compte. Jonathan Lewis dans la discussion que j'ai ouverte sur OTN disait qu'il était possible que cette fois le choix ait été effectué en prenant en compte l'ordre alphabétique.
Vu qu'alphabétiquement P_TRANSRPDATES soit avant R_TRANSRPDATES_ACCIK on peut effectivement penser cela.
J'ai donc refait le test en renommant l'index non unique en A_TRANSRPDATES_ACCIK pour qu'il soit alphabétiquement avant l'index unique:
J'ai écrit cet article pour montrer que l'optimiseur d'Oracle a des secrets au niveau de son algorithme que même le grand Jonathan LEWIS n'a pas encore totalement percé car le comportement du CBO varie énormément selon les paramètres, les modèles de données et les requêtes impliquées.
Néanmoins, la vraie conclusion de cette petite expérience c'est qu'il faut absolument se méfier des stats calculés sur des tables vides pour éviter des mésaventures qui peuvent s'avérer extrêmement coûteuses dans un environnement de production.
DELETE FROM SCDAT.TRANSRPDATES WHERE TRANSRPDATES.TRANSIK = :v1 AND TRANSRPDATES.ACCIK = :v2;
On peut constater cela en regardant les stats au niveau de l'AWR:
SNAP_ID NODE BEGIN_INTERVAL_TIME SQL_ID PLAN_HASH_VALUE EXECS AVG_ETIME AVG_LIO AVG_PIO AVG_ROWS
---------- ------ ------------------------------ ------------- --------------- ------------ ------------ -------------- ---------- ------------
55 1 20/02/14 17:00:25,756 9ytthuuffcgy5 2252980867 1,263 1.271 15,226.1 ,406967538 1
56 1 20/02/14 18:00:41,362 9ytthuuffcgy5 2,915 1.238 15,213.3 ,208919383 1
57 1 20/02/14 19:00:54,602 9ytthuuffcgy5 2,822 1.258 15,195.6 ,242026931 1
58 1 20/02/14 20:00:07,686 9ytthuuffcgy5 2,895 1.248 15,178.0 ,12193437 1
59 1 20/02/14 21:00:21,148 9ytthuuffcgy5 2,918 1.242 15,160.2 ,257710761 1
60 1 20/02/14 22:00:36,358 9ytthuuffcgy5 2,888 1.248 15,142.3 ,233379501 1
61 1 20/02/14 23:00:51,105 9ytthuuffcgy5 2,881 1.232 15,124.6 ,144741409 1
62 1 21/02/14 00:00:04,016 9ytthuuffcgy5 2,932 1.231 15,106.6 ,224079127 1
63 1 21/02/14 01:00:17,342 9ytthuuffcgy5 2,949 1.224 15,084.1 ,143438454 1
64 1 21/02/14 02:00:30,694 9ytthuuffcgy5 2,952 1.223 15,070.2 ,103319783 1
65 1 21/02/14 03:00:43,780 9ytthuuffcgy5 2,959 1.220 15,051.9 ,100033795 1
66 1 21/02/14 04:00:56,915 9ytthuuffcgy5 2,924 1.214 15,033.7 ,157660739 1
67 1 21/02/14 05:00:09,943 9ytthuuffcgy5 2,971 1.216 15,015.5 ,100302928 1
68 1 21/02/14 06:00:23,053 9ytthuuffcgy5 2,989 1.208 14,997.1 ,096353295 1
69 1 21/02/14 07:00:36,366 9ytthuuffcgy5 2,991 1.207 14,978.6 ,235372785 1
70 1 21/02/14 08:00:49,468 9ytthuuffcgy5 2,943 1.207 14,960.2 ,285762827 1
71 1 21/02/14 09:00:02,396 9ytthuuffcgy5 3,001 1.203 14,941.7 ,154948351 1
72 1 21/02/14 10:00:15,559 9ytthuuffcgy5 2,803 1.201 14,920.2 ,172315376 1
148 1 24/02/14 17:00:54,112 9ytthuuffcgy5 2250495236 63,142 .001 70.2 ,077428653 1
On voit qu'on a eu un switch de plan le 24/02/2014. Avant cette date le plan utilisé générait environ 15000 logical reads par exécution alors que le 24/02/14 le nouveau plan ne générait plus que 70 LR par exécution.
Voyons à quoi ressemble ces 2 plans:
Plan hash value: 2250495236 ----------------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ----------------------------------------------------------------------------------------------- | 0 | DELETE STATEMENT | | | | 3 (100)| | | 1 | DELETE | TRANSRPDATES | | | | | | 2 | TABLE ACCESS BY INDEX ROWID| TRANSRPDATES | 1 | 40 | 3 (0)| 00:00:01 | | 3 | INDEX UNIQUE SCAN | P_TRANSRPDATES | 1 | | 2 (0)| 00:00:01 | ----------------------------------------------------------------------------------------------- Plan hash value: 2252980867 ----------------------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ----------------------------------------------------------------------------------------------------- | 0 | DELETE STATEMENT | | | | 2 (100)| | | 1 | DELETE | TRANSRPDATES | | | | | | 2 | TABLE ACCESS BY INDEX ROWID| TRANSRPDATES | 1 | 92 | 2 (0)| 00:00:01 | | 3 | INDEX RANGE SCAN | R_TRANSRPDATES_ACCIK | 1 | | 2 (0)| 00:00:01 | -----------------------------------------------------------------------------------------------------
On remarque que le bon plan consiste en une opération INDEX UNIQUE SCAN alors que le mauvais correspond à une opération INDEX RANGE SCAN. En gros, la requête s'exécute bien lorsque l'index unique P_TRANSRPDATES est utilisé, et s'exécute nettement moins bien lorsque l'index non-unique R_TRANSRPDATES_ACCIK est utilisé.
L'index unique est un index composite sur les 2 colonnes impliquées dans la requête alors que l'index non-unique est un index sur la colonne ACCIK uniquement.
La question légitime qu'on se pose c'est "pourquoi le CBO a décidé d'utiliser l'index non-unique avant la date du 24/02 alors que l'index unique existait bien?".
Pour répondre à cette question j'ai fait un comparatif des stats entre la date du jour et la date du 21/02 en utilisant la procédure DIFF_TABLE_STATS_IN_HISTORY du package DBMS_STATS:
SELECT *
FROM table(dbms_stats.diff_table_stats_in_history(
ownname => 'SCDAT',
tabname => 'TRANSRPDATES',
time1 => systimestamp - to_dsinterval('5 00:00:00'),
time2 => NULL,
pctthreshold => 10));
###############################################################################
STATISTICS DIFFERENCE REPORT FOR:
.................................
TABLE : TRANSRPDATES
OWNER : SCDAT
SOURCE A : Statistics as of 21/02/14 09:19:30,901433 +01:00
SOURCE B : Current Statistics in dictionary
PCTTHRESHOLD : 10
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
TABLE / (SUB)PARTITION STATISTICS DIFFERENCE:
.............................................
OBJECTNAME TYP SRC ROWS BLOCKS ROWLEN SAMPSIZE
...............................................................................
TRANSRPDATES T A 0 33172 0 0
B 63293 33172 40 63293
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
COLUMN STATISTICS DIFFERENCE:
.............................
COLUMN_NAME SRC NDV DENSITY HIST NULLS LEN MIN MAX SAMPSIZ
...............................................................................
ACCIK A 0 0 NO 0 0 0
B 1 ,000008023 YES 0 4 C2020 C2020 5415
RPDEFIK A 0 0 NO 0 0 0
B 1 ,000008023 YES 0 2 80 80 5415
TRANSIK A 0 0 NO 0 0 0
B 63048 ,000016047 YES 0 6 C4043 C4054 5415
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
INDEX / (SUB)PARTITION STATISTICS DIFFERENCE:
.............................................
OBJECTNAME TYP SRC ROWS LEAFBLK DISTKEY LF/KY DB/KY CLF LVL SAMPSIZ
...............................................................................
INDEX: P_TRANSRPDATES
.....................
P_TRANSRPDATES I A 0 0 0 0 0 0 2 0
B 63293 763 63293 1 1 31603 2 63293
INDEX: R_TRANSRPDATES_ACCIK
...........................
R_TRANSRPDATES_ I A 0 0 0 0 0 0 2 0
B 63293 223 1 223 580 580 2 63293
INDEX: R_TRANSRPDATES_RPDEFIK
.............................
R_TRANSRPDATES_ I A 0 0 0 0 0 0 2 0
B 63293 214 1 214 580 580 2 63293
###############################################################################
On constate qu'en réalité à la date du 21 les stats étaient à zéro c'est à dire que les stats avaient été calculées alors que la table était vide.
Il ne faut pas confondre ici les stats à zéro et les stats à NULL. Les stats à NULL signifient une absence de stats et donc dans ce cas le Dynamic Sampling peut être activé selon la valeur du paramètre OPTIMIZER_DYNAMIC_SAMPLING.
Dans notre cas les stats étaient à zéro avant le 24 ce qui veut dire que le CBO estimait qu'il n'y avait pas de données dans la table alors qu'en réalité bien sûr il y'en avait.
L'idée ensuite est de pouvoir reproduire le mauvais plan en activant une trace 10053 lorsque les stats sont à zéro.
J'ai pour cela restauré les stats à la date du 21/02:
exec DBMS_STATS.RESTORE_TABLE_STATS (ownname=>'SCDAT', tabname=>'TRANSRPDATES', as_of_timestamp=>TO_DATE('21/02/2014 09:19:30', 'DD/MM/YYYY HH24:MI:SS'));
@10053
explain plan for
DELETE FROM SCDAT.TRANSRPDATES WHERE TRANSRPDATES.TRANSIK = :v1 AND TRANSRPDATES.ACCIK = :v2;
@dis_10053
Plan hash value: 2252980867
-----------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-----------------------------------------------------------------------------------------------------
| 0 | DELETE STATEMENT | | 1 | 92 | 2 (0)| 00:00:01 |
| 1 | DELETE | TRANSRPDATES | | | | |
|* 2 | TABLE ACCESS BY INDEX ROWID| TRANSRPDATES | 1 | 92 | 2 (0)| 00:00:01 |
|* 3 | INDEX RANGE SCAN | R_TRANSRPDATES_ACCIK | 1 | | 2 (0)| 00:00:01 |
-----------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - filter("TRANSRPDATES"."TRANSIK"=TO_NUMBER(:V1))
3 - access("TRANSRPDATES"."ACCIK"=TO_NUMBER(:V2))
BINGO!! L'optimiseur a choisi l'index non-unique.
Jettons un oeil à la trace du CBO:
***************************************
BASE STATISTICAL INFORMATION
***********************
Table Stats::
Table: TRANSRPDATES Alias: TRANSRPDATES
#Rows: 0 #Blks: 33172 AvgRowLen: 0.00 ChainCnt: 0.00
Index Stats::
Index: P_TRANSRPDATES Col#: 1 2
LVLS: 2 #LB: 0 #DK: 0 LB/K: 0.00 DB/K: 0.00 CLUF: 0.00
Index: R_TRANSRPDATES_ACCIK Col#: 2
LVLS: 2 #LB: 0 #DK: 0 LB/K: 0.00 DB/K: 0.00 CLUF: 0.00
Index: R_TRANSRPDATES_RPDEFIK Col#: 6
LVLS: 2 #LB: 0 #DK: 0 LB/K: 0.00 DB/K: 0.00 CLUF: 0.00
***************************************
1-ROW TABLES: TRANSRPDATES[TRANSRPDATES]#0
Access path analysis for TRANSRPDATES
***************************************
SINGLE TABLE ACCESS PATH
Single Table Cardinality Estimation for TRANSRPDATES[TRANSRPDATES]
Column (#1): TRANSIK(
AvgLen: 22 NDV: 0 Nulls: 0 Density: 0.000000 Min: 0 Max: 0
Column (#2): ACCIK(
AvgLen: 22 NDV: 0 Nulls: 0 Density: 0.000000 Min: 0 Max: 0
ColGroup (#1, Index) P_TRANSRPDATES
Col#: 1 2 CorStregth: 0.00
ColGroup Usage:: PredCnt: 2 Matches Full: #1 Partial: Sel: 1.0000
Table: TRANSRPDATES Alias: TRANSRPDATES
Card: Original: 0.000000 Rounded: 1 Computed: 0.00 Non Adjusted: 0.00
Access Path: TableScan
Cost: 9540.36 Resp: 9540.36 Degree: 0
Cost_io: 9479.00 Cost_cpu: 236232408
Resp_io: 9479.00 Resp_cpu: 236232408
Access Path: index (UniqueScan)
Index: P_TRANSRPDATES
resc_io: 2.00 resc_cpu: 15583
ix_sel: 0.000000 ix_sel_with_filters: 0.000000
Cost: 2.00 Resp: 2.00 Degree: 1
ColGroup Usage:: PredCnt: 2 Matches Full: #1 Partial: Sel: 1.0000
ColGroup Usage:: PredCnt: 2 Matches Full: #1 Partial: Sel: 1.0000
Access Path: index (AllEqUnique)
Index: P_TRANSRPDATES
resc_io: 2.00 resc_cpu: 15583
ix_sel: 1.000000 ix_sel_with_filters: 1.000000
Cost: 2.00 Resp: 2.00 Degree: 1
Access Path: index (AllEqRange)
Index: R_TRANSRPDATES_ACCIK
resc_io: 2.00 resc_cpu: 14443
ix_sel: 0.010000 ix_sel_with_filters: 0.010000
Cost: 2.00 Resp: 2.00 Degree: 1
Best:: AccessPath: IndexRange
Index: R_TRANSRPDATES_ACCIK
Cost: 2.00 Degree: 1 Resp: 2.00 Card: 0.00 Bytes: 0
Le CBO calcule le COST pour chaque index et on voit que le COST est à 2 pour chacun d'eux.
Logiquement on s'imagine qu'il prendrait l'index unique mais en fait pas du tout...il prend l'index non unique.
Mon sentiment au départ était de dire que le CBO choisissait l'index qui était potentiellement le plus petit c'est à dire celui qui contenait le moins de clés d'index.
En effet dans mon cas l'index non unique est définie sur seulement une seule colonne alors que l'index unique est définie sur 2 colonnes.
Pour en savoir plus j'ai décidé d'ouvrir une discussion sur le forum d'OTN et j'ai envoyé un mail au spécialiste du CBO Jonathan LEWIS pour l'inviter à y répondre.
Bien sûr Jonathan a répondu et voici sa réponse:
For a tie in the cost of the index: at one time the choice was alphabetical by name but a fix came in some time in 10g to select the index with the larger number of distinct keys.Donc, selon Jonathan, lorsqu'on a un COST identique et qu'on est en présence à la fois d'un index UNIQUE et d'un index non-unique, le CBO choisirait automatiquement l'index non-unique.
At present is seems to be:
If all indexes are unique and the costs are the same then tie-break on number of distinct keys, if those match then alphabetical.
If all indexes are non-unique and the costs are the same then tie-break on number of distinct keys, if those match then alphabetical.
If there is a mixture of unique and non-unique then NON-unique are preferred
Je trouve ça complètement illogique surtout lorsque l'on sait que les index range scan par rapport aux index unique scan entrainent un surcoût lié notamment au nombre de latchs plus importants générés et au fait qu'en cas d'index range scan oracle doit checker l'entrée d'index suivant (juste au cas où) car cette opération par définition peut retourner plusieurs lignes alors qu'avec un index unqiue scan Oracle est sûr de n'avoir au plus qu'une seule entrée d'index correspondante.
Je vous invite à lire l'article de Richard FOOTE sur ce sujet.
Pour en revenir à mon cas et pour confirmer mon hypothèse de départ sur le nombre de colonnes, j'ai (sur les conseils de mon ami Guy-Georges DROGBA) généré de nouveau le plan après avoir cette fois désactivé le CPU costing:
exec DBMS_STATS.RESTORE_TABLE_STATS (ownname=>'SCDAT', tabname=>'TRANSRPDATES', as_of_timestamp=>TO_DATE('21/02/2014 09:19:30', 'DD/MM/YYYY HH24:MI:SS'));
alter session set "_optimizer_cost_model"=io;
@10053
explain plan for DELETE FROM SCDAT.TRANSRPDATES WHERE TRANSRPDATES.TRANSIK = :v1 AND TRANSRPDATES.ACCIK = :v2;
@dis_10053
@plan
Plan hash value: 2250495236
-------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost |
-------------------------------------------------------------------------------
| 0 | DELETE STATEMENT | | 1 | 92 | 2 |
| 1 | DELETE | TRANSRPDATES | | | |
| 2 | TABLE ACCESS BY INDEX ROWID| TRANSRPDATES | 1 | 92 | 2 |
|* 3 | INDEX UNIQUE SCAN | P_TRANSRPDATES | 1 | | 2 |
-------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
3 - access("TRANSRPDATES"."TRANSIK"=TO_NUMBER(:V1) AND
"TRANSRPDATES"."ACCIK"=TO_NUMBER(:V2))
alter session set "_optimizer_cost_model"=cpu;
explain plan for DELETE FROM SCDAT.TRANSRPDATES WHERE TRANSRPDATES.TRANSIK = :v1 AND TRANSRPDATES.ACCIK = :v2;
@plan
Plan hash value: 2252980867
-----------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-----------------------------------------------------------------------------------------------------
| 0 | DELETE STATEMENT | | 1 | 92 | 2 (0)| 00:00:01 |
| 1 | DELETE | TRANSRPDATES | | | | |
|* 2 | TABLE ACCESS BY INDEX ROWID| TRANSRPDATES | 1 | 92 | 2 (0)| 00:00:01 |
|* 3 | INDEX RANGE SCAN | R_TRANSRPDATES_ACCIK | 1 | | 2 (0)| 00:00:01 |
-----------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - filter("TRANSRPDATES"."TRANSIK"=TO_NUMBER(:V1))
3 - access("TRANSRPDATES"."ACCIK"=TO_NUMBER(:V2))
exec DBMS_STATS.RESTORE_TABLE_STATS (ownname=>'SCDAT', tabname=>'TRANSRPDATES', as_of_timestamp=>systimestamp-1, force=> TRUE);
Ah! cette fois lorsque le CPU costing est désactivé c'est bien l'index unique qui est pris en compte. Jonathan Lewis dans la discussion que j'ai ouverte sur OTN disait qu'il était possible que cette fois le choix ait été effectué en prenant en compte l'ordre alphabétique.
Vu qu'alphabétiquement P_TRANSRPDATES soit avant R_TRANSRPDATES_ACCIK on peut effectivement penser cela.
J'ai donc refait le test en renommant l'index non unique en A_TRANSRPDATES_ACCIK pour qu'il soit alphabétiquement avant l'index unique:
exec DBMS_STATS.RESTORE_TABLE_STATS (ownname=>'SCDAT', tabname=>'TRANSRPDATES', as_of_timestamp=>TO_DATE('21/02/2014 09:19:30', 'DD/MM/YYYY HH24:MI:SS'));
alter session set "_optimizer_cost_model"=io;
alter index SCDAT.R_TRANSRPDATES_ACCIK rename to A_TRANSRPDATES_ACCIK;
@10053
explain plan for DELETE FROM SCDAT.TRANSRPDATES WHERE TRANSRPDATES.TRANSIK = :v1 AND TRANSRPDATES.ACCIK = :v2;
@dis_10053
@plan
Plan hash value: 2250495236
-------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost |
-------------------------------------------------------------------------------
| 0 | DELETE STATEMENT | | 1 | 92 | 2 |
| 1 | DELETE | TRANSRPDATES | | | |
| 2 | TABLE ACCESS BY INDEX ROWID| TRANSRPDATES | 1 | 92 | 2 |
|* 3 | INDEX UNIQUE SCAN | P_TRANSRPDATES | 1 | | 2 |
-------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
3 - access("TRANSRPDATES"."TRANSIK"=TO_NUMBER(:V1) AND
"TRANSRPDATES"."ACCIK"=TO_NUMBER(:V2))
Note
-----
- cpu costing is off (consider enabling it)
alter session set "_optimizer_cost_model"=cpu;
explain plan for DELETE FROM SCDAT.TRANSRPDATES WHERE TRANSRPDATES.TRANSIK = :v1 AND TRANSRPDATES.ACCIK = :v2;
@plan
Plan hash value: 1992853963
-----------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-----------------------------------------------------------------------------------------------------
| 0 | DELETE STATEMENT | | 1 | 92 | 2 (0)| 00:00:01 |
| 1 | DELETE | TRANSRPDATES | | | | |
|* 2 | TABLE ACCESS BY INDEX ROWID| TRANSRPDATES | 1 | 92 | 2 (0)| 00:00:01 |
|* 3 | INDEX RANGE SCAN | A_TRANSRPDATES_ACCIK | 1 | | 2 (0)| 00:00:01 |
-----------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - filter("TRANSRPDATES"."TRANSIK"=TO_NUMBER(:V1))
3 - access("TRANSRPDATES"."ACCIK"=TO_NUMBER(:V2))
alter index SCDAT.A_TRANSRPDATES_ACCIK rename to R_TRANSRPDATES_ACCIK;
exec DBMS_STATS.RESTORE_TABLE_STATS (ownname=>'SCDAT', tabname=>'TRANSRPDATES', as_of_timestamp=>systimestamp-1, force=> TRUE);
C'est toujours l'index unique qui est pris en compte. Donc on peut dire que dans mon cas lorsque le CPU costing est désactivé c'est l'index unique qui est pris en compte alors que si le CPU costing est activé c'est l'index non unique qui est pris en compte.
Et la raison c'est surement qu'il est moins couteux d'un point de vue CPU de parcourir un index sur une seule colonne (mon index non-unique) qu'un index sur 2 colonnes (mon index unique).
Néanmoins, la vraie conclusion de cette petite expérience c'est qu'il faut absolument se méfier des stats calculés sur des tables vides pour éviter des mésaventures qui peuvent s'avérer extrêmement coûteuses dans un environnement de production.
