Plan d'exécution avec un bind variable

**couak** · 15/10/2009, 09h26

Bonjour,

J'ai un problème bizarre avec un progiciel sur une requête qui utilise une bind variable. La requête est en elle-même assez simple, sur une table de 1,7 millions de lignes :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
SELECT A.DOC_ID,A.STAMP_UID,A.STAMP_DATE,A.LOG_INDEX,A.LOG_COMMENT
FROM ACTION_LOG A WHERE (( A.DOC_ID = :PAR_FILTER0_0 ));

Par contre, malgré des stats à jour et la présence d'un index sur DOC_ID le plan d'exécution est catastrophique :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
select * from table(dbms_xplan.display_cursor('d4mkvkrz4q58s',null,'ADVANCED'))
 
SQL_ID  d4mkvkrz4q58s, child number 1
-------------------------------------
SELECT A.DOC_ID,A.STAMP_UID,A.STAMP_DATE,A.LOG_INDEX,A.LOG_COMMENT
  )A.DOC_ID = :PAR_FILTER0_0 )
 
Plan hash value: 367639580
 
--------------------------------------------------------------------------------
| Id  | Operation         | Name       | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |            |       |       |  5138 (100)|          |
|*  1 |  TABLE ACCESS FULL| ACTION_LOG |   189K|    15M|  5138   (1)| 00:01:02 |
--------------------------------------------------------------------------------
 
Predicate Information (identified by operation id):
---------------------------------------------------
 
   1 - filter("A"."DOC_ID"=:PAR_FILTER0_0)

Pour invalider le plan d'exécution, je fais une opération de type DDL sur la table (REVOKE ou GRANT) et là je me retrouve avec un plan d'exécution correcte sur ce SQL ID :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
-------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name              | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |                   |       |       |     9 (100)|          |
|   1 |  TABLE ACCESS BY INDEX ROWID| ACTION_LOG        |    16 |  1392 |     9   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | ACTION_LOG_DOC_ID |    16 |       |     3   (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------

Problème : au bout d'un certain temps (genre le lendemain), il me refait le coup du plan d'exécution foireux. C'est particulièrement gênant car ca sollicite le disque, et le progiciel n'arrête pas d'utiliser cette requête qui met 1 min à s'exécuter. Existe-t-il une façon de forcer le plan d'exécution mis à part le hint (car je n'ai pas la main sur le progiciel) ?

Mon environnement :
- Windows 2003 Server
- Oracle 10.2.0.4 32 bits, Enterprise Edition

**13thFloor** · 15/10/2009, 09h55

Bonjour,
qu'est-ce qui te dit que le plan est foireux ?
Si la valeur bindée est très présente dans la table, l'optimiseur estime, à juste titre, qu'il est plus avantageux de lire complètement la table.
As-tu un histogramme sur cette colonne ?
Comment sont réparties les différentes valeurs ?

**farenheiit** · 15/10/2009, 11h02

Quel est le résultat de la requête suivante:

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
 
select DOC_ID, count(1)
from 
ACTION_LOG
group by DOC_ID
order by 2 desc

Combien de lignes y'a t'il dans ta table ACTION_LOG ?
Y'a t'il bien environ 189 000 lignes dans ta table qui ont un DOC_ID testé par le progiciel ?

**couak** · 15/10/2009, 11h50

Envoyé par 13thFloor

Bonjour,
qu'est-ce qui te dit que le plan est foireux ?
Si la valeur bindée est très présente dans la table, l'optimiseur estime, à juste titre, qu'il est plus avantageux de lire complètement la table.
As-tu un histogramme sur cette colonne ?
Comment sont réparties les différentes valeurs ?

Foireux car quand il fait son FULL TABLE SCAN ca prend 1 min, et en utilisant l'index ca prend 1 sec. J'ai énormément d'I/O disque quand il fait le full scan

Les différentes valeurs sont répartie de la sorte : il y a entre 1 à 30 fois la même valeur

**couak** · 15/10/2009, 11h52

Envoyé par farenheiit

Quel est le résultat de la requête suivante:

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
 
select DOC_ID, count(1)
from 
ACTION_LOG
group by DOC_ID
order by 2 desc

Combien de lignes y'a t'il dans ta table ACTION_LOG ?
Y'a t'il bien environ 189 000 lignes dans ta table qui ont un DOC_ID testé par le progiciel ?

1,7 millions de lignes
les stats sont mises à jour toutes les nuits, avec un échantillon à 100%

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
SQL> select num_rows from user_tables where table_name='ACTION_LOG';
 
  NUM_ROWS
----------
   1784853

le résultat de ta requête me donne 102 727

**farenheiit** · 15/10/2009, 12h09

102727 ? pour quel DOC_ID ?
quelle est la valeur du DOC_ID que tu testes quand ta requête met une minute ?

le mieux pour comparer les cardinalités estimées et les cardinalités réelles c'est de faire la chose suivante:

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
 
alter session set statistics_level=all;
 
SELECT A.DOC_ID,A.STAMP_UID,A.STAMP_DATE,A.LOG_INDEX,A.LOG_COMMENT
FROM ACTION_LOG A WHERE (( A.DOC_ID = :PAR_FILTER0_0 ));
 
SELECT * FROM table(dbms_xplan.display_cursor(NULL,NULL,'iostats last'));

remplace la variable bindée par la valeur du DOC_ID que tu veux tester.

Ensuite on pourra comparer les colonnes E-rows et A-rows.

**13thFloor** · 15/10/2009, 14h07

Un histogramme réglera sans doute le problème :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

 exec dbms_stats.gather_table_stats('SCHEMA','ACTION_LOG',estimate_percent=>100,method_opt=>'for method_opt=>'for columns DOC_ID size auto');

**couak** · 15/10/2009, 14h15

Envoyé par farenheiit

102727 ? pour quel DOC_ID ?
quelle est la valeur du DOC_ID que tu testes quand ta requête met une minute ?

102727 c'est le nbre de lignes retournées

en fait j'ai entre 1 à 30 DOC_ID identiques dans cette table de 1,7 millions de lignes pour un nbre total de 102727 DOC_ID distinct

pour la cardinalité :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
-----------------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name              | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
-----------------------------------------------------------------------------------------------------------
|   1 |  TABLE ACCESS BY INDEX ROWID| ACTION_LOG        |      1 |     16 |     19 |00:00:00.01 |      10 |
|*  2 |   INDEX RANGE SCAN          | ACTION_LOG_DOC_ID |      1 |     16 |     19 |00:00:00.01 |       3 |
-----------------------------------------------------------------------------------------------------------

le problème c'est que maintenant qu'il utilise l'index ca m'a l'air tout bon... ce qui me gêne c'est que demain je vais sûrement me retrouver avec un plan d'exécution qui fait un full scan sur une table de 1,7 millions de lignes

**farenheiit** · 15/10/2009, 14h28

Envoyé par 13thFloor

Un histogramme réglera sans doute le problème :

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

 exec dbms_stats.gather_table_stats('SCHEMA','ACTION_LOG',estimate_percent=>100,method_opt=>'for method_opt=>'for columns DOC_ID size auto');

L'histogramme ne réglera pas le pb s'il utilise des binds variables car l'optimiseur va prendre en compte la valeur de la variable lors de la 1ère exécution.

combien de child as tu pour ton sql_id ?

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
 
select child_number from v$sql where sql_id = 'd4mkvkrz4q58s';

**couak** · 15/10/2009, 14h41

Envoyé par farenheiit

L'histogramme ne réglera pas le pb s'il utilise des binds variables car l'optimiseur va prendre en compte la valeur de la variable lors de la 1ère exécution.

combien de child as tu pour ton sql_id ?

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
 
select child_number from v$sql where sql_id = 'd4mkvkrz4q58s';

1 seul child

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
CHILD_NUMBER           
---------------------- 
2                      
 
1 rows selected

**farenheiit** · 15/10/2009, 14h43

tu peux regarder dans l'AWR ?

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
 
SELECT child_number FROM DBA_HIST_SQLTEXT WHERE sql_id = 'd4mkvkrz4q58s';

**couak** · 15/10/2009, 14h48

Envoyé par farenheiit

tu peux regarder dans l'AWR ?

1 ligne

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
SQL> SELECT sql_id FROM DBA_HIST_SQLTEXT WHERE sql_id = 'd4mkvkrz4q58s';
 
SQL_ID
-------------
d4mkvkrz4q58s

**mongolic** · 15/10/2009, 15h10

Bonjour,

si le child_number est passé à deux , c'est qu'il y a eu à un moment trois versions différentes dans v$sql sans doute avec des plans distincts car oracle a estimé que la bind variable n'était pas 'safe' (en fonction de la valorisation de la bind variable, un plan distinct peut être nécessaire).
J'ai également vu un cas où les histogrammes ne suffisaient pas à oracle à effectuer le bon choix: si tu as une valeur représenté 1 fois et une valeur représentée 50000 fois qui se retrouve dans le même intervalle des histogrammes, oracle applique le même plan pour les deux valeurs ! Il y en aura un des deux plan qui ne sera pas judicieux.

**farenheiit** · 15/10/2009, 15h14

désolé je me suis trompé dans ma requête. Essaye ça:

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
 
select distinct SQL_CHILD_NUMBER from DBA_HIST_ACTIVE_SESS_HISTORY where sql_id = 'd4mkvkrz4q58s'

**couak** · 15/10/2009, 15h18

sur metalink j'ai trouvé la note 430208.1 qui donne un exemple sur le bind peeking
la piste était donné dès le début par farenheiit sur la cardinalité, avec une valeur qui implique un plan d'exécution avec un FTS

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
8
9
10
11
DOC_ID                                                           COUNT(1)               
---------------------------------------------------------------- ---------------------- 
E34E63BD72BA434DA749304374CC3C22                                 191578                 
SYSTEM                                                           1534                   
B18762C8E38A4EF78E4B13E462A4D611                                 373                    
483A8404C95341B5A24DC5D887C32510                                 370                    
9F3B8E152CC04D77927D2C6E986D03B4                                 368                    
C6AABACFF357436295FA905E38E94B87                                 363                    
126B19C7EFC149A4B4FD1B8A0D9C5421                                 363                    
39891B95599142DAB2DBDD37354567C2                                 363                    
F9355325E83F4030AA6A6ECB81A12B00                                 363

**farenheiit** · 15/10/2009, 15h51

En fait voilà ce qu'il se passe:
imaginons que t'execute la 1ère fois la requete sur doc_id='E34E63BD72BA434DA749304374CC3C22' il y'a de fortes chances qu'à ce moment le CBO choisisse un FTS. Lors de cette 1ère execution le CBO peek la valeur de la bind variable et l'utilise comme un litteral. Le pb c'est que lors de la 2ème execution de ta requête avec la valeur DOC_ID='B18762C8E38A4EF78E4B13E462A4D611' le CBO va utiliser le même curseur et le même child . Il va donc générer un plan avec un FTS alors qu'un accès par l'index aurait été plus judicieux.
Tant que le curseur est dans la shared_pool t'auras le même pb.

En 11g il existe l'Extended Cursor Sharing qui permet au CBO de reconnaitre automatiquement que la réutilisation d'un shared cursor engendre des pb de perfs.

En 10G la seule solution est d'abandonner les bind variables

**mongolic** · 15/10/2009, 15h56

Envoyé par farenheiit

En fait voilà ce qu'il se passe:
imaginons que t'execute la 1ère fois la requete sur doc_id='E34E63BD72BA434DA749304374CC3C22' il y'a de fortes chances qu'à ce moment le CBO choisisse un FTS. Lors de cette 1ère execution le CBO peek la valeur de la bind variable et l'utilise comme un litteral. Le pb c'est que lors de la 2ème execution de ta requête avec la valeur DOC_ID='B18762C8E38A4EF78E4B13E462A4D611' le CBO va utiliser le même curseur et le même child . Il va donc générer un plan avec un FTS alors qu'un accès par l'index aurait été plus judicieux.
Tant que le curseur est dans la shared_pool t'auras le même pb.

En 11g il existe l'Extended Cursor Sharing qui permet au CBO de reconnaitre automatiquement que la réutilisation d'un shared cursor engendre des pb de perfs.

En 10G la seule solution est d'abandonner les bind variables

**mongolic** · 15/10/2009, 16h01

Envoyé par farenheiit

En fait voilà ce qu'il se passe:
imaginons que t'execute la 1ère fois la requete sur doc_id='E34E63BD72BA434DA749304374CC3C22' il y'a de fortes chances qu'à ce moment le CBO choisisse un FTS. Lors de cette 1ère execution le CBO peek la valeur de la bind variable et l'utilise comme un litteral. Le pb c'est que lors de la 2ème execution de ta requête avec la valeur DOC_ID='B18762C8E38A4EF78E4B13E462A4D611' le CBO va utiliser le même curseur et le même child . Il va donc générer un plan avec un FTS alors qu'un accès par l'index aurait été plus judicieux.
Tant que le curseur est dans la shared_pool t'auras le même pb.

En 11g il existe l'Extended Cursor Sharing qui permet au CBO de reconnaitre automatiquement que la réutilisation d'un shared cursor engendre des pb de perfs.

En 10G la seule solution est d'abandonner les bind variables

Je pensais que s'il y avait plusieurs child_number, c'est qu'oracle avait effectué plusieurs hard parse pour la même requête car il considérait que le plan d'exécution pouvait varier et là il a un child_number à 2 comme s'il avait effectué trois hard parse ?

**farenheiit** · 15/10/2009, 16h09

Oui c'est vrai mais le pb c'est que les 2 premiers child_number ont disparu de la shared_pool. S'ils avaient été présent on aurait pu trouver la cause du mismatch via la vue v$sql_shared_cursor

D'ailleurs COUAC peux tu executuer la requete suivante:

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

select child_number from v$sql_shared_cursor WHERE sql_id ='d4mkvkrz4q58s'

**couak** · 15/10/2009, 16h39

Envoyé par farenheiit

Oui c'est vrai mais le pb c'est que les 2 premiers child_number ont disparu de la shared_pool. S'ils avaient été présent on aurait pu trouver la cause du mismatch via la vue v$sql_shared_cursor

D'ailleurs COUAC peux tu executuer la requete suivante:

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

select child_number from v$sql_shared_cursor WHERE sql_id ='d4mkvkrz4q58s'

arggh cette fois j'en ai 2

Code :

Sélectionner tout - Visualiser dans une fenêtre à part

1
2
3
4
5
6
7
SQL> SELECT child_number FROM v$sql_shared_cursor WHERE sql_id ='d4mkvkrz4q58s';
 
 
CHILD_NUMBER
------------
           0
           2

Plan d'exécution avec un bind variable

Administration Oracle

Discussions similaires

Partager

Partager