Analyse avec Tkprof d'une requête [Résolu]

[Knonix]

Bonjour à tous, et d'avance je suis desolé si mon sujet n'est pas au bon endroit mais je suis un newbiz dans la communauté de developpez.

Mon soucis est le suivant :
Migration d'une base Oracle 8i en 9i, la migration a été effectué par la méthode suivante :
Création d'une nouvelle base 9 (j'ai sur dimensionné la mémoire actuellement)
Export du schéma de la 8i
Import dans la nouvelle base 9i

Les 2 machines sont des Solaris8 qui tiennent la route (V880 et V490).

Tout est Ok sauf que l'on vient de s'apercevoir qu'une requête simple mettait énormément de temps à ramener des lignes sur la base 9 (45mn) alors que la même requête avec autant de ligne en production ne met que 11s sur la base 8i et ici en dev sur le V880 avec la moitié du nombre de lignes que 6s.

Mon premier réflexe a été de vérifier les paramètres mémoires de la base, puis mes param systèmes mais tout me semble OK.

Donc par la suite j'ai utilisé les traces et l'outil tkprof, voici les résultats des tests :

Code :

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
 
TABLE : 
TSTOCK (
  STDATE             DATE          NOT NULL, 
  MATID               NUMBER (5)    NOT NULL, 
  EMPID               NUMBER (10)   NOT NULL, 
  SITID               NUMBER (10)   NOT NULL,
  QUANTITE         NUMBER (15,3),
  SMATORIG       VARCHAR2 (10)  NOT NULL,
  MID           NUMBER (5), 
  SIT_NOM          VARCHAR2 (30))
PRIMARY KEY ( STDATE, MATID, EMPID, SMATORIGINE ) 
INDEX ON TSTOCK(MATID) 
INDEX ON TSTOCK(EMPID) 
INDEX ON TSTOCK(SMATORIGINE)
INDEX ON TSTOCK(SITID) 
INDEX ON TSTOCK(SIT_NOM)
La TABLE et les INDEX sont dans 2 tablespace séparé.

Code :

1
2
3
4
5
 
Requete : SELECT S.SIT_NOM,  sum(S.QUANTITE) FROM TSTOCK S
WHERE S.SMFM_ID = 10000 AND S.MID = 7 AND S.STDATE = (
     SELECT max(M.stdate) FROM TSTOCK M  WHERE  M.SITID = S.SITID AND MID = S.MID  AND M.SMFM_ID = 10000)
GROUP BY S.SSIT_NOM

Test 1 : Lancement de la requête sur la base Oracle8i (la table contient 500 000 Lignes)

Code :

1
2
3
4
5
6
7
8
9
10
11
12
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        2      0.00       0.02          0          0          0           0
Execute      2      0.00       0.00          0          0          0           0
Fetch        2      3.01       3.23       2067     303626          0          30
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        6      3.01       3.25       2067     303626          0          30
 
Misses IN library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 58  ()

Ici tout semble OK

Test 2 : Lancement de la requête sur la base Oracle9i (la table contient 1 300 000 Lignes)

Code :

1
2
3
4
5
6
7
8
9
10
11
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.04       0.03          0          0          0           0
Execute      2      0.00       0.00          0          0          0           0
Fetch        2   5934.76    5841.47     103485      59932          0          15
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        5   5934.80    5841.50     103485      59932          0          15
 
Misses IN library cache during parse: 1
Misses IN library cache during execute: 1

ici cela me donne l'impression que les index ne sont pas utilisés, (pourtant j'ai réalisé un rebuild de ces derniers).

test 3: Lancement de la requête sur la base Oracle9i (la table contient 1 300 000 Lignes) mais cette fois j'ai crée une seconde table TSTOCK2 identique à la première et avec les même index :

Code :

1
2
3
4
5
6
7
8
9
10
11
12
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2     15.22      16.08      70459     578349          0          15
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4     15.23      16.09      70459     578349          0          15
 
Misses IN library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 23  ()

Test 4: J'ai supprimé les index (PK et autres de la table) puis je les ai recrées (afin d'être sur que tout est Ok sur ces derniers et cela a empiré le temps de traitement.

Code :

1
2
3
4
5
6
7
8
9
10
11
12
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.02       0.02          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2   6123.46    5989.88      48658      48660          0          15
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4   6123.48    5989.91      48658      48660          0          15
 
Misses IN library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 23  ()

Voila j'y perds mon chinois et donc mon SQL, si quelqu'un à une proposition à me faire sur la raison de cela, je suis preneur, en espérant avoir été clair.
Merci à tous.

[Michel SALAIS]

Envoyé par Knonix

Bonjour à tous, et d'avance je suis desolé si mon sujet n'est pas au bon endroit mais je suis un newbiz dans la communauté de developpez.

Mon soucis est le suivant :
Migration d'une base Oracle 8i en 9i, la migration a été effectué par la méthode suivante :
Création d'une nouvelle base 9 (j'ai sur dimensionné la mémoire actuellement)
Export du schéma de la 8i
Import dans la nouvelle base 9i

Les 2 machines sont des Solaris8 qui tiennent la route (V880 et V490).

Tout est Ok sauf que l'on vient de s'apercevoir qu'une requête simple mettait énormément de temps à ramener des lignes sur la base 9 (45mn) alors que la même requête avec autant de ligne en production ne met que 11s sur la base 8i et ici en dev sur le V880 avec la moitié du nombre de lignes que 6s.

Mon premier réflexe a été de vérifier les paramètres mémoires de la base, puis mes param systèmes mais tout me semble OK.

Donc par la suite j'ai utilisé les traces et l'outil tkprof, voici les résultats des tests :





Test 1 : Lancement de la requête sur la base Oracle8i (la table contient 500 000 Lignes)


Ici tout semble OK

Test 2 : Lancement de la requête sur la base Oracle9i (la table contient 1 300 000 Lignes)

ici cela me donne l'impression que les index ne sont pas utilisés, (pourtant j'ai réalisé un rebuild de ces derniers).

test 3: Lancement de la requête sur la base Oracle9i (la table contient 1 300 000 Lignes) mais cette fois j'ai crée une seconde table TSTOCK2 identique à la première et avec les même index :


Test 4: J'ai supprimé les index (PK et autres de la table) puis je les ai recrées (afin d'être sur que tout est Ok sur ces derniers et cela a empiré le temps de traitement.


Voila j'y perds mon chinois et donc mon SQL, si quelqu'un à une proposition à me faire sur la raison de cela, je suis preneur, en espérant avoir été clair.
Merci à tous.

Le plan utilisé est aussi dans le rapport tkprof et il ne s'agit pas de deviner!
Maintenant, est-ce-que les stats ont été collectées sur les index?

[Knonix]

Ok en effet j'avais pas mis le plan d'execution :

Pour mémo :
Index
TSTOCK_FK : index sur MATID
TSTOCK_FK3 : index sur SITID

Plan du test sous Oracle 8 (test1)

Code :

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
 
Rows     Execution Plan
-------  ---------------------------------------------------
      0  SELECT STATEMENT   GOAL: CHOOSE
     15   SORT (GROUP BY)
     36    FILTER
  38124     TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                'TSTOCK'
  38124      INDEX   GOAL: ANALYZED (RANGE SCAN) OF 'TSTOCK_FK' 
                 (NON-UNIQUE)
     30     SORT (AGGREGATE)
  38123      TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                 'TETAT_STOCK'
  38138       AND-EQUAL
  90759        INDEX   GOAL: ANALYZED (RANGE SCAN) OF 
                   'TSTOCK_FK' (NON-UNIQUE)
  78832        INDEX   GOAL: ANALYZED (RANGE SCAN) OF 
                   'TSTOCK_FK3' (NON-UNIQUE)

Il utilise bien les index

Plan du test sous Oracle9 (test2)

Code :

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
 
Rows     Execution Plan
-------  ---------------------------------------------------
      0  SELECT STATEMENT   GOAL: CHOOSE
      0   SORT (GROUP BY)
      0    VIEW
      0     FILTER
      0      SORT (GROUP BY)
      0       HASH JOIN
      0        TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'TSTOCK'
      0        TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'TSTOCK'
 
********************************************************************************
 
ALTER SESSION SET SQL_TRACE=true

Il fait un scan Full, pourquoi ?????

Plan du test sous Oracle 9(test3)

Code :

1
2
3
4
5
6
7
8
9
10
11
12
13
 
Rows     Execution Plan
-------  ---------------------------------------------------
      0  SELECT STATEMENT   GOAL: CHOOSE
      0   SORT (GROUP BY)
      0    FILTER
      0     TABLE ACCESS (BY INDEX ROWID) OF 'TSTOCK2'
      0      INDEX (RANGE SCAN) OF 'TSTOCK2_FK' (NON-UNIQUE)
      0     SORT (AGGREGATE)
      0      TABLE ACCESS (BY INDEX ROWID) OF 'TSTOCK2'
      0       AND-EQUAL
      0        INDEX (RANGE SCAN) OF 'TSTOCK2_FK3' (NON-UNIQUE)
      0        INDEX (RANGE SCAN) OF 'TSTOCK2_FK' (NON-UNIQUE)

Il utilise bien les index

Plan du test 4 sous Oracle9

Code :

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
 
Rows     Execution Plan
-------  ---------------------------------------------------
      0  SELECT STATEMENT   GOAL: CHOOSE
      0   SORT (GROUP BY)
      0    VIEW
      0     FILTER
      0      SORT (GROUP BY)
      0       HASH JOIN
      0        TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                   'TETAT_STOCK'
      0         INDEX (RANGE SCAN) OF 'TSTOCK_FK' (NON-UNIQUE)
      0        TABLE ACCESS   GOAL: ANALYZED (BY INDEX ROWID) OF 
                   'TSTOCK'
      0         INDEX (RANGE SCAN) OF 'TSTOCK_FK' (NON-UNIQUE)

Là je comprends plus rien !!!!

Quand à mes stats normalement je les avais recalculé (premiére chose à laquelle j'avais pensé) ... mais je l'avoue via Toad (7). Je viens de relancer une Requête compléte de recalcul de mes stats sur la table et ces index :

Code :

1
2
 
ANALYZE TABLE TSTOCK ESTIMATE STATISTICS SAMPLE ;

J'ai relancé la requête sur la table et cela tourne depuis 5mn sans apparente amélioration.

Mais par curiosité je croyais que le fait de supprimer les index et de les récréer faisait que les stats étaient inutile à être recalculé ?

[orafrance]

Les stats ne sont pas calculées automatiquement... le ROWS a 0 laisse à penser qu'elles manquent.

Donc GO pour un DBMS_STATS

[Knonix]

Merci pour la réponse, je pense qu'en effet nous sommes sur la bonne voie :
mais lorsque je lance le recalcul des stats j'obtiens ce message d'erreur :

Code :

1
2
3
4
5
6
7
8
9
10
11
12
13
 
SQL> exec dbms_stats.gather_schema_stats(ownname=> 'PRINVAL' , options => 'GATHER', cascade=> TRUE );
BEGIN dbms_stats.gather_schema_stats(ownname=> 'PRINVAL' , options => 'GATHER', cascade=> TRUE ); END;
 
*
ERREUR à la ligne 1 :
ORA-00933: La commande SQL ne se termine pas correctement
ORA-06512: à "SYS.DBMS_STATS", ligne 9375
ORA-06512: à "SYS.DBMS_STATS", ligne 9857
ORA-06512: à "SYS.DBMS_STATS", ligne 10041
ORA-06512: à "SYS.DBMS_STATS", ligne 10095
ORA-06512: à "SYS.DBMS_STATS", ligne 10072
ORA-06512: à ligne 1

Cela indiquerait que j'aurais un problème dans mes stats ?

Je précise qu'aprés controle nous avons des erreurs de stats qui sont remontés avec l'import de la base 8 et cela semble être repertorié par un bug oracle. Que l'on peut soit disant contourner lors de l'import par les options ANALYZE=N ou/et RECALCULATE_STATISTICS=Y, pouvez vous me le confimer ?

[orafrance]

bah si il y a un bug... j'peux pas faire autrement que confirmer

[Knonix]

Bien je vous remercie pour m'avoir mis sur la piste des stats qui je pense était la bonne.
Le bug provient bien de notre version d'oracle 9.2.0.4 qui avec l'option d'import analyze=N :
1) ne provoque plus d'erreur lors de l'import
2) permet d'avoir une base dans un état cohérent et d'avoir nos requêtes qui se mettent à fonctionner correctement, temps et plan d'exécution correct.

Seul subsiste le problème de l'exécution du package dbms_stat toujours en erreur sur l'analyse d'un schéma, mais cela est une autre histoire.