Plan d'exécution avec un bind variable

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:

---

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:

---

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:

---

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

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 ?

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

Code:

---

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 ?

Citation:

---

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

Citation:

---

Envoyé par farenheiit

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

Code:

---

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:

---

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

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:

---

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.

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

Code:

---

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

---

Citation:

---

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:

---

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

Citation:

---

Envoyé par 13thFloor

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

Code:

---

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:

---

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

---

Citation:

---

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:

---

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

---

---

1 seul child

Code:

---

1 2 3 4 5

CHILD_NUMBER ---------------------- 2   1 rows selected

---

tu peux regarder dans l'AWR ?

Code:

---

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

---

Citation:

---

Envoyé par farenheiit

tu peux regarder dans l'AWR ?

---

1 ligne

Code:

---

1 2 3 4 5

SQL> SELECT sql_id FROM DBA_HIST_SQLTEXT WHERE sql_id = 'd4mkvkrz4q58s';   SQL_ID ------------- d4mkvkrz4q58s

---

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.

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

Code:

---

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

---

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:

---

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

---

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

Citation:

---

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

---

Citation:

---

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 ?

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:

---

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

---

Citation:

---

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:

---

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

---

---

arggh cette fois j'en ai 2

Code:

---

1 2 3 4 5 6 7

SQL> SELECT child_number FROM v$sql_shared_cursor WHERE sql_id ='d4mkvkrz4q58s';     CHILD_NUMBER ------------ 0 2

---

bonne nouvelle.

execute la requête suivante pour voir sir le plan d'execution pour les 2 child sont différents:

Code:

---

1 2	select distinct child_number, plan_hash_value from v$sql_plan where sql_id = 'd4mkvkrz4q58s';

---

puis execute cette requête pour voir le mismatch entre les 2 childs:

Code:

---

1 2	select * from v$sql_shared_cursor where sql_id = 'd4mkvkrz4q58s';

---

ce qui serait intéressant de voir, ce sont les raisons des différences entre les deux child cursor (càd les colonnes de v$sql_shared_cursor )

un troisième child cursor a effectivement pû être généré mais il a peut être tout simplement été "aged out" de la cache

pour ce qui est d'abandonner les bind variables, la bonne pratique en 10g est d'utiliser des bind variables lorsque la dispersion de tes données est homogène . si tu dois sélectionner des données qui ont une cardinalités très différentes de celles utilisées pour le bind peeking, n'utilise dans ce cas précis pas de bind variable

les options 11g bind sensitives règlent plus ou moins ce problème

1 seul plan d'exécution

Code:

---

1 2 3

CHILD_NUMBER PLAN_HASH_VALUE ------------ --------------- 2 3366992749

---

mismatch

Code:

---

1 2 3 4

SQL_ID ADDRESS CHILD_AD CHILD_NUMBER U S O O S L S E B P I S T A B D L T R I I R L I O S M U T N F A I T D L D B P C S R P T M B M R O P M F L ------------- -------- -------- ------------ - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - d4mkvkrz4q58s 301DBB5C 3362755C 0 N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N d4mkvkrz4q58s 301DBB5C 31A17264 2 N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N

---

A mon avis suite à l'invalidation que j'avais faite sur le curseur, j'ai 1 seul plan d'exécution valide. Il faudrait juste refaire tout ca quand le plan d'exécution qui fait un FTS se représente.
De toute manière j'ai vu avec les responsables applicatif, c'est un bug du progiciel qui alimente cette table (historique des actions) pour un document en erreur.
La boucle est bouclé, on va purger la table des historiques sur le document incriminé avec la validation de l'éditeur :)

Merci pour vos lumières