Aide sur un plan d'exécution

Version imprimable

Bonsoir,

J'ai une même requête qui a des temps d'exécution différents.
Au début la réponse est immédiate puis si je la lance plusieurs fois de suite elle prend plusieurs minutes.

Code:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47

Voici ce que l’on obtient alors que le temps de réponse est normal    (voire immédiat)

Plan d'exécution
----------------------------------------------------------
Plan hash value: 626068950

------------------------------------------------------------------------------------------------
| Id  | Operation                        | Name        | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                 |             |     1 |     7 |   246   (2)| 00:00:03 |
|   1 |  SORT ORDER BY                   |             |     1 |     7 |   246   (2)| 00:00:03 |
|   2 |   VIEW                           | VM_NWVW_2   |     1 |     7 |   246   (2)| 00:00:03 | ?
|   3 |    HASH UNIQUE                   |             |     1 |    70 |   246   (2)| 00:00:03 |
|   4 |     NESTED LOOPS                 |             |     3 |   210 |   245   (2)| 00:00:03 |
|   5 |      NESTED LOOPS                |             |     3 |   174 |   245   (2)| 00:00:03 |
|*  6 |       TABLE ACCESS FULL          | PARTICIPER  |     4 |   108 |   241   (2)| 00:00:03 |
|*  7 |       TABLE ACCESS BY INDEX ROWID| ADHERENT    |     1 |    31 |     1   (0)| 00:00:01 |
|*  8 |        INDEX UNIQUE SCAN         | PK_ADHERENT |     1 |       |     0   (0)| 00:00:01 |
|*  9 |      INDEX UNIQUE SCAN           | PK_AGPRDTVA |     1 |    12 |     0   (0)| 00:00:01 |
------------------------------------------------------------------------------------------------

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

   6 - filter(NVL("FL_FACTURE",0)=0 AND SUBSTR("ESS_ID",1,2)=SUBSTR(TO_CHAR(2015,'9999')
              ,4,2) AND NVL("FL_CALENDAR",0)=1 AND NVL("FL_DESINSCRIPTION",0)=0)
   7 - filter(NVL("ADHE_CLOTURE",0)=0 AND "TARI_TYPE_FACT"<>'NONE')
   8 - access("ADHE_ID"=DECODE("FL_FACTCONS",1,"GET_CONSO_ADHERENT"("PARTICIPER"."ADHE_I
              D"),"PARTICIPER"."ADHE_ID"))
   9 - access("AGPRDTVA"."PRDT_PROD"='P' AND "AGPRDTVA"."PRDT_PAYS"="PAYS_ID")


Statistiques
----------------------------------------------------------
        332  recursive calls
          0  db block gets
       1747  consistent gets
          0  physical reads
          0  redo size
        437  bytes sent via SQL*Net to client
        349  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          1  sorts (memory)
          0  sorts (disk)
          8  rows processed

Code:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49

Voici ce que l’on obtient alors que le temps de réponse est anormalement long   (env  2 min voire plus)

Cela se produit en général lors de la 3ème ou 4ème exécution de la requête.

Plan d'exécution
----------------------------------------------------------
Plan hash value: 626068950

------------------------------------------------------------------------------------------------
| Id  | Operation                        | Name        | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                 |             |     1 |     7 |   246   (2)| 00:00:03 |
|   1 |  SORT ORDER BY                   |             |     1 |     7 |   246   (2)| 00:00:03 |
|   2 |   VIEW                           | VM_NWVW_2   |     1 |     7 |   246   (2)| 00:00:03 | ?
|   3 |    HASH UNIQUE                   |             |     1 |    70 |   246   (2)| 00:00:03 |
|   4 |     NESTED LOOPS                 |             |     3 |   210 |   245   (2)| 00:00:03 |
|   5 |      NESTED LOOPS                |             |     3 |   174 |   245   (2)| 00:00:03 |
|*  6 |       TABLE ACCESS FULL          | PARTICIPER  |     4 |   108 |   241   (2)| 00:00:03 |
|*  7 |       TABLE ACCESS BY INDEX ROWID| ADHERENT    |     1 |    31 |     1   (0)| 00:00:01 |
|*  8 |        INDEX UNIQUE SCAN         | PK_ADHERENT |     1 |       |     0   (0)| 00:00:01 |
|*  9 |      INDEX UNIQUE SCAN           | PK_AGPRDTVA |     1 |    12 |     0   (0)| 00:00:01 |
------------------------------------------------------------------------------------------------

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

   6 - filter(NVL("FL_FACTURE",0)=0 AND SUBSTR("ESS_ID",1,2)=SUBSTR(TO_CHAR(2015,'9999')
              ,4,2) AND NVL("FL_CALENDAR",0)=1 AND NVL("FL_DESINSCRIPTION",0)=0)
   7 - filter(NVL("ADHE_CLOTURE",0)=0 AND "TARI_TYPE_FACT"<>'NONE')
   8 - access("ADHE_ID"=DECODE("FL_FACTCONS",1,"GET_CONSO_ADHERENT"("PARTICIPER"."ADHE_I
             D"),"PARTICIPER"."ADHE_ID"))
   9 - access("AGPRDTVA"."PRDT_PROD"='P' AND "AGPRDTVA"."PRDT_PAYS"="PAYS_ID")


Statistiques
----------------------------------------------------------
     643120  recursive calls
          0  db block gets
    3069812  consistent gets
          0  physical reads
          0  redo size
        437  bytes sent via SQL*Net to client
        349  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          1  sorts (memory)
          0  sorts (disk)
          8  rows processed

Je ne comprends pas :

à quoi correspond la vue VM_NWVW_2 ?
que le coût et la durée entre les deux plans d'exécution sont les mêmes alors que dans la réalité le 2ème résultat est beaucoup plus long ?
à quoi correspond recursive calls et consistent gets et pourquoi ils explosent entre les deux plans d'exécution ?

Merci d'avance pour vos éclairages et vos pistes de recherche.

Deux plans ayant la même plan_hash_value (et très probablement la même phv2) d'une requête qui n'utilise pas les bind variables et re-exécutée exactement à l'identique et qui n'a pas utilisé la notion de cardinality feedback mais qui montre dans son exécution la plus lente une explosion des recursive calls et des consistent gets, tout cela me fait penser que c'est probablement des lectures consistantes à partir de l'undo dues à des update dans les tables sélectionnées.

Obtenez votre sql_id correspondant et consulter ash en groupant par current_obj# sur db file sequential read
Code:

1 2 3 4 5 6 7 SQL> select current_obj#, count(1) 2 from gv$active_session_history 3 where sql_id ='125xthehjkej' 4 and event = 'db file sequential read' 5 group by current_obj# 6 order by 2 desc;
si c'est l'object 0 qui domine alors vous avez votre réponse

Bien Cordialement
Mohamed Houri

09/10/2015, 15h01
mnitu
Citation:
Envoyé par canabral

...
Je ne comprends pas :

à quoi correspond la vue VM_NWVW_2 ?
...
A la transformation par l'optimiseur de votre requête: Complex view merging
14/10/2015, 17h54
canabral
Bonsoir,

Merci pour vos réponses.

j'ai récupéré le sql_id avec :
Code:

1 2 3 4 select sql_id, substr(sql_text,1,200) sql_text from v$sql where sql_text like 'select ADHE from%';
Mais la requête conseillée ne me retourne rien ? Est-ce normal ?
Code:

1 2 3 4 5 6 7 select current_obj#, count(1) from gv$active_session_history where sql_id ='5n9zbmac7k0at' and event = 'db file sequential read' group by current_obj# order by 2 desc;
Après ce phénomène de lenteur ce produit après avoir exécuté la requête plusieurs fois à la suite, sans qu'il y ait eu de UPDATE...

A quoi correspondent les recursive calls et des consistent gets ?

Merci pour vos explications.
15/10/2015, 09h33
mnitu

"recursive calls" : votre requête génère parfois des autres requêtes. Le cas typique arrive lors du hard parsing de la requête: Oracle a besoin des informations pour élaborer le plan d'exécution optimale (cardinalités, histogrammes, indexes, présence des nuls, etc) donc il va lire son méta dictionnaire via des requêtes SQL. L'autre exemple typique est l'encapsulation des requêtes SQL dans des fonctions PL/SQL et l'utilisation des ces dernières dans les requêtes SQL. Pareil pour les triggers et toute la cuisine interne d'Oracle.

"consistent gets" : lecture normale d'un block des données à partir du buffer cache. Il y aura une vérification de la version du block pour décider si c'est nécessaire de reconstruire une image consistante des données par rapport au moment de début de la requête via le rollback. Donc elle peut prendre en considération les modifications fait par vous ou autres que ces modification on été validées (via commit) ou pas. Mais le plus souvent c'est juste de la lecture du block.
15/10/2015, 16h34
canabral

Bonjour et merci.

Lorsque j'utilise cette requête avec une bind variable je n'ai plus ce problème de lenteur.
J'ai également repris la requête pour la simplifier supression de jointure inutile, ajout de jointure utile, supression de sous-requête, ... et le plan d'exécution est beaucoup mieux.

Je revois ces points avec notre prestataire pour vérifier comment ces requêtes sont intégrées dans les développements.
16/10/2015, 09h39
mnitu

La requête qui utilise des variables de liaison est différente de la requête qui ne les utilise pas! La requête modifiée est différente de la requête originale et il faut bien vérifier qu'elle est équivalente!
Aucune de ces nouvelles requêtes n'a rien à voir avec la choucroute!
La choucroute est "nombre de buffer gets" et "recursive calls" augmente d'une manière impressionnante lors de la réexécution de la requête avec un fort impact sur le temps d'exécution. Si vous ne comprenez pourquoi alors vous fait un peu n'importe quoi juste en espérant que le problème va disparaitre. Assez bien vous pouvez essayer de croiser les doigts, parfois ça marché ou juste de "positiver".
16/10/2015, 11h43
canabral

Bonjour,

Je comprends bien la problèmatique.

Citation:

La requête qui utilise des variables de liaison est différente de la requête qui ne les utilise pas!

Oui, mais la requête qui en utilise aura une meilleure optimisation que la requête qui n'en utilise pas ?

Citation:

La requête modifiée est différente de la requête originale et il faut bien vérifier qu'elle est équivalente!

Oui, sinon on aura un bug, cette modification doit donc être validée !

Citation:

Aucune de ces nouvelles requêtes n'a rien à voir avec la choucroute!
La choucroute est "nombre de buffer gets" et "recursive calls" augmente d'une manière impressionnante lors de la réexécution de la requête avec un fort impact sur le temps d'exécution. Si vous ne comprenez pourquoi alors vous fait un peu n'importe quoi juste en espérant que le problème va disparaitre.

Je pensais qu'optimiser la requête rendrait la choucroute meilleure !
Par exemple en modifiant cette requête, elle génère peu-être moins d'autres requêtes et donc améliore les "recursive calls"...?

Comment fait-on pour comprendre pourquoi la choucroute n'était pas bonne innitialement ??

Bon appétit ! ;)
16/10/2015, 13h56
mnitu

Bonjour,

Citation:

Envoyé par canabral

Oui, mais la requête qui en utilise aura une meilleure optimisation que la requête qui n'en utilise pas ?

Oui et non; en réalité cela dépende.

Citation:

Envoyé par canabral

Je pensais qu'optimiser la requête rendrait la choucroute meilleure !
Par exemple en modifiant cette requête, elle génère peu-être moins d'autres requêtes et donc améliore les "recursive calls"...?

Et que est-ce que il vous fait penser que la nouvelle requête ne suffira pas de la même problématique ? Si le nombre des "buffers gets" diminue c'est une bonne chose mais si ils sont due a une cause non lié directement avec le plan d'exécution cela ne vous servira à rien. Idem pour les "recursives calls".

Citation:

Envoyé par canabral

Comment fait-on pour comprendre pourquoi la choucroute n'était pas bonne innitialement ??

En analysant ce qui se passe. L'ensemble des requêtes, récursives ou pas, peut être obtenu via la trace sql étendue ainsi que les détails des buffers gets.

Citation:

Bon appétit !

Merci à vous ça a été :)