Performances et fonctions custom ?

**brolon** · 20/12/2010, 09h25

Bonjour à tous,

Deux des scripts de l'ETL sur lequel je travaille chargent environ 18 millions de lignes chacun. Bien que le nombre de lignes et le nombre de colonnes soit relativement semblables, les performances sont grandement différentes:

Script 1:

18601974 rows created.
Elapsed: 01:17:05.21

Script 2:

18669334 rows created.
Elapsed: 00:02:21.37

Les deux scripts sont des "insert into (...) select (...) from", réalisés avec les hints append et parallel. Jusqu'ici la situation est assez similaire. Dans le script 1, une jointure est réalisée entre une grosse table d'input et deux petits subsets d'une table de mapping. Dans le script 2, aucune jointure n'est réalisée à partir de la table d'input.

Dans le cas du script 1, des index sont présents sur les colonnes utilisées pour réaliser la jointure, tant au niveau de la table d'input qu'au niveau de la table de mapping.

Malgré cela, la jointure peut-elle expliquer une si grande différence de performance entre les deux scripts?

Une autre chose qui est différente entre les deux scripts est que dans le script 1, on utilise des fonctions "customs" (pour convertir certains champs de type date) tandis que dans le script 2, on n'utilise que des fonctions "built-in".

Cela peut-il avoir un impact sur les performances?

D'avance, merci pour vos réponses.

**Waldar** · 20/12/2010, 10h01

Envoyé par brolon

Malgré cela, la jointure peut-elle expliquer une si grande différence de performance entre les deux scripts ?

Une trace avec explain plan pourra expliquer ce phénomène, là comme ça difficile d'être factuel.

Envoyé par brolon

dans le script 1, on utilise des fonctions "customs" (pour convertir certains champs de type date) tandis que dans le script 2, on n'utilise que des fonctions "built-in".

Cela peut-il avoir un impact sur les performances ?

Oui, c'est certain, ça dépend vraiment de comment est écrite la fonction.

**brolon** · 20/12/2010, 10h21

Voici l'explain plan obtenu dans toad. Pour ce test, la table d'input contient 2500000 records.

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
21
22
Plan
INSERT STATEMENT  ALL_ROWSCost: 1,566  Bytes: 339,999,456  Cardinality: 2,499,996  															
	20 LOAD AS SELECT CMC.CMC_CONTRACTS_CLOSED 														
		19 PX COORDINATOR  													
			18 PX SEND QC (RANDOM) PARALLEL_TO_SERIAL SYS.:TQ10002 Cost: 1,566  Bytes: 339,999,456  Cardinality: 2,499,996  												
				17 HASH JOIN PARALLEL_COMBINED_WITH_PARENT Cost: 1,566  Bytes: 339,999,456  Cardinality: 2,499,996  											
					14 PX RECEIVE PARALLEL_COMBINED_WITH_PARENT Cost: 8  Bytes: 98,790  Cardinality: 1,110  										
						13 PX SEND BROADCAST PARALLEL_TO_PARALLEL SYS.:TQ10001 Cost: 8  Bytes: 98,790  Cardinality: 1,110  									
							12 MERGE JOIN CARTESIAN PARALLEL_COMBINED_WITH_PARENT Cost: 8  Bytes: 98,790  Cardinality: 1,110  								
								3 SORT JOIN PARALLEL_COMBINED_WITH_PARENT 							
									2 PX BLOCK ITERATOR PARALLEL_COMBINED_WITH_CHILD Cost: 2  Bytes: 120  Cardinality: 3  						
										1 TABLE ACCESS FULL TABLE PARALLEL_COMBINED_WITH_PARENT CMC.CMC_CODIFICATION Cost: 2  Bytes: 120  Cardinality: 3  					
								11 BUFFER SORT PARALLEL_COMBINED_WITH_PARENT Cost: 6  Bytes: 18,130  Cardinality: 370  							
									10 BUFFER SORT PARALLEL_COMBINED_WITH_CHILD 						
										9 PX RECEIVE PARALLEL_COMBINED_WITH_PARENT Bytes: 18,130  Cardinality: 370  					
											8 PX SEND BROADCAST PARALLEL_FROM_SERIAL SYS.:TQ10000 Bytes: 18,130  Cardinality: 370  				
												7 VIEW VIEW CMC.V_CMC_COD_NATURE Bytes: 18,130  Cardinality: 370  			
													6 SORT ORDER BY  Cost: 3  Bytes: 14,800  Cardinality: 370  		
														5 TABLE ACCESS BY INDEX ROWID TABLE CMC.CMC_CODIFICATION Cost: 2  Bytes: 14,800  Cardinality: 370  	
															4 INDEX RANGE SCAN INDEX CMC.CMC_IDE_CODIF_CODE_I Cost: 1  Cardinality: 370  
					16 PX BLOCK ITERATOR PARALLEL_COMBINED_WITH_CHILD Cost: 1,550  Bytes: 117,499,812  Cardinality: 2,499,996  										
						15 TABLE ACCESS FULL TABLE PARALLEL_COMBINED_WITH_PARENT CMCE.ETL_AMI_IN_CTF Cost: 1,550  Bytes: 117,499,812  Cardinality: 2,499,996

Concernant les fonctions, elles sont écrites assez simplement. Voici un exemple:

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
CREATE OR REPLACE FUNCTION VNC."VNC_CONVERT_DATE" (InDate IN VARCHAR2)
RETURN DATE
IS
 
    OutDate DATE;
 
BEGIN
 
    IF InDate <> '00000000' and InDate <> '19404040' and InDate <> '65069569' THEN
        OutDate := to_date(InDate,'YYYYMMDD');
    ELSE
        OutDate := null;
    END IF;
 
    RETURN OutDate;
END VNC_CONVERT_DATE;
/

**spdev666** · 20/12/2010, 11h03

Bonjour,

Je suppose que si la différence viens de la fonction "custom", cela doit être visible en ne s'intéressant qu'aux selects, en dehors des inserts.

Peut être aussi que le la différence vient des index qui doivent être maintenus à jour sur les deux tables : il y en a peut etre plus sur la table 1 ?

**Waldar** · 20/12/2010, 11h32

Difficile à relire votre plan, utilisez cette méthode sous Toad (execute as a script) :

Code :

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

1
2
3
4
5
6
7
set linesize 250;
-- À adapter selon le résultat visuel
 
explain plan for
votre_select;
 
SELECT * FROM TABLE(dbms_xplan.display);

Il faut aussi l'analyse TKPROF de la trace pour savoir où est consommé le temps :

Code :

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

1
2
3
4
5
alter session set events '10046 trace name context forever, level 12';
 
votre_select;
 
alter session set events '10046 trace name context off';

**brolon** · 20/12/2010, 12h26

Voici l'explain plan, qui j'espère sera plus lisible:

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
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
Explain complete.
 
PLAN_TABLE_OUTPUT                                                                                                                                                                                                                                         
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 3618009043                                                                                                                                                                                                                               
 
----------------------------------------------------------------------------------------------------------------------------------------------                                                                                                            
| Id  | Operation                                | Name                 | Rows  | Bytes | Cost (%CPU)| Time     |    TQ  |IN-OUT| PQ Distrib |                                                                                                            
----------------------------------------------------------------------------------------------------------------------------------------------                                                                                                            
|   0 | INSERT STATEMENT                         |                      |  2499K|   324M|  1566   (3)| 00:00:19 |        |      |            |                                                                                                            
|   1 |  LOAD AS SELECT                          | VNC_BIG_TABLE        |       |       |            |          |        |      |            |                                                                                                            
|   2 |   PX COORDINATOR                         |                      |       |       |            |          |        |      |            |                                                                                                            
|   3 |    PX SEND QC (RANDOM)                   | :TQ10002             |  2499K|   324M|  1566   (3)| 00:00:19 |  Q1,02 | P->S | QC (RAND)  |                                                                                                            
|*  4 |     HASH JOIN                            |                      |  2499K|   324M|  1566   (3)| 00:00:19 |  Q1,02 | PCWP |            |                                                                                                            
|   5 |      PX RECEIVE                          |                      |  1110 | 98790 |     8  (13)| 00:00:01 |  Q1,02 | PCWP |            |                                                                                                            
|   6 |       PX SEND BROADCAST                  | :TQ10001             |  1110 | 98790 |     8  (13)| 00:00:01 |  Q1,01 | P->P | BROADCAST  |                                                                                                            
|   7 |        MERGE JOIN CARTESIAN              |                      |  1110 | 98790 |     8  (13)| 00:00:01 |  Q1,01 | PCWP |            |                                                                                                            
|   8 |         SORT JOIN                        |                      |       |       |            |          |  Q1,01 | PCWP |            |                                                                                                            
|   9 |          PX BLOCK ITERATOR               |                      |     3 |   120 |     2   (0)| 00:00:01 |  Q1,01 | PCWC |            |                                                                                                            
|* 10 |           TABLE ACCESS FULL              | VNC_CODIFICATION     |     3 |   120 |     2   (0)| 00:00:01 |  Q1,01 | PCWP |            |                                                                                                            
|  11 |         BUFFER SORT                      |                      |   370 | 18130 |     6  (17)| 00:00:01 |  Q1,01 | PCWP |            |                                                                                                            
|  12 |          BUFFER SORT                     |                      |       |       |            |          |  Q1,01 | PCWC |            |                                                                                                            
|  13 |           PX RECEIVE                     |                      |   370 | 18130 |            |          |  Q1,01 | PCWP |            |                                                                                                            
|  14 |            PX SEND BROADCAST             | :TQ10000             |   370 | 18130 |            |          |        | S->P | BROADCAST  |                                                                                                            
|  15 |             VIEW                         | V_VNC_COD_NATURE     |   370 | 18130 |            |          |        |      |            |                                                                                                            
|  16 |              SORT ORDER BY               |                      |   370 | 14800 |     3  (34)| 00:00:01 |        |      |            |                                                                                                            
|  17 |               TABLE ACCESS BY INDEX ROWID| VNC_CODIFICATION     |   370 | 14800 |     2   (0)| 00:00:01 |        |      |            |                                                                                                            
|* 18 |                INDEX RANGE SCAN          | VNC_IDE_CODIF_CODE_I |   370 |       |     1   (0)| 00:00:01 |        |      |            |                                                                                                            
|  19 |      PX BLOCK ITERATOR                   |                      |  2499K|   112M|  1550   (2)| 00:00:19 |  Q1,02 | PCWC |            |                                                                                                            
|* 20 |       TABLE ACCESS FULL                  | ETL_BIG_TABLE        |  2499K|   112M|  1550   (2)| 00:00:19 |  Q1,02 | PCWP |            |                                                                                                            
----------------------------------------------------------------------------------------------------------------------------------------------                                                                                                            
 
Predicate Information (identified by operation id):                                                                                                                                                                                                       
---------------------------------------------------                                                                                                                                                                                                       
 
   4 - access("ETL_BIG_TABLE"."COD_PRIV_PROF"="IDE_CODE" AND "V_VNC_COD_NATURE"."IDE_CODE"="ETL_BIG_TABLE"."COD_NATURE")                                                                                                                                
  10 - filter("IDE_CODIF_CODE"='COD_PRIV_PROF')                                                                                                                                                                                                           
  18 - access("IDE_CODIF_CODE"='COD_NATURE')                                                                                                                                                                                                              
  20 - filter("CUST_IDE_NPERS"<>'0000000000')                                                                                                                                                                                                             
 
 
35 rows selected.

Lorsque j'essaie d'obtenir le résultat de tkprof, j'obtiens une erreur de type 'insufficient privileges'.

**Waldar** · 20/12/2010, 12h40

C'est le plan de quelle requête celui-ci, la lente ou la rapide ?

Pour la trace, voyez auprès de votre DBA, le fichier sera écrit dans ce répertoire :

Code :

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

1
2
3
SELECT value
  FROM sys.v_$diag_info
 WHERE name = 'Default Trace File';

**mnitu** · 20/12/2010, 14h46

Dans votre exemple, votre fonction peut être remplacée par un case. Si vous avez N fonctions exécutez pour chaque enregistrement disons M il y a des forte chances que vous allez faire N * M changement de contexte entre le moteur SQL et PL/SQL. C’est à éviter. Bien sûr, sans trace SQL il sera hasardeux d’expliquer toute la différence de temps d’exécution par ce phénomène.

**brolon** · 20/12/2010, 16h15

@mnitu, merci pour cette explication.

Voici deux traces que j'ai générées avec 'SET AUTOTRACE'...

Script 'lent':

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
2484822 rows created.
Elapsed: 00:05:27.95
 
Execution Plan
----------------------------------------------------------
 
 
Statistics
----------------------------------------------------------
      25035  recursive calls
       8776  physical write total multi block requests
          0  gcs messages sent
    1416621  db block gets from cache
     661781  redo entries
          0  java session heap live size
          0  java session heap live size max
          0  java session heap object count
          0  java session heap gc count
          0  java session heap collected count
    2484822  rows processed

Script 'rapide':

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
2500000 rows created.
Elapsed: 00:00:16.12
 
Execution Plan
----------------------------------------------------------
 
 
Statistics
----------------------------------------------------------
        643  recursive calls
          0  physical write total multi block requests
          0  gcs messages sent
       1318  db block gets from cache
        404  redo entries
          0  java session heap live size
          0  java session heap live size max
          0  java session heap object count
          0  java session heap gc count
          0  java session heap collected count
    2500000  rows processed

On constate une grosse différence au niveau du redo alors que les 2 tables sont en mode 'NOLOGGING'.

Que signifie la partie "physical write total multi block requests" ?

D'avance, merci.

**mnitu** · 20/12/2010, 16h44

Statistics Descriptions

physical write total multi block requests
8
Total number of Oracle instance write requests which wrote two or more blocks per request to the disk for all instance activity including application activity, recovery and backup, and other utilities.

**brolon** · 21/12/2010, 11h05

Voilà, j'ai pu obtenir les traces. C'est la première fois que j'en analyse donc je m'en vais chercher de la documentation sur comment interpréter cela. Peut-être quelque chose va-t-il déjà vous sauter aux yeux ; )

1) Pour le script lent :

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
21
22
23
24
25
26
27
28
29
30
31
32
33
34
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.27       1.44          0          0          0           0
Execute      1    351.86     381.03     204979     116912    1435156     2484822
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2    352.13     382.48     204979     116912    1435156     2484822
 
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 143  (CMC_AS1)
 
Rows     Row Source Operation
-------  ---------------------------------------------------
      1  LOAD AS SELECT  (cr=125165 pr=204987 pw=236719 time=381982110 us)
2484822   PX COORDINATOR  (cr=20 pr=4 pw=0 time=12638501 us)
      0    PX SEND QC (RANDOM) :TQ10002 (cr=0 pr=0 pw=0 time=0 us)
      0     HASH JOIN  (cr=0 pr=0 pw=0 time=0 us)
      0      PX RECEIVE  (cr=0 pr=0 pw=0 time=0 us)
      0       PX SEND BROADCAST :TQ10001 (cr=0 pr=0 pw=0 time=0 us)
      0        MERGE JOIN CARTESIAN (cr=0 pr=0 pw=0 time=0 us)
      0         SORT JOIN (cr=0 pr=0 pw=0 time=0 us)
      0          PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)
      0           TABLE ACCESS FULL VNC_CODIFICATION (cr=0 pr=0 pw=0 time=0 us)
      0         BUFFER SORT (cr=0 pr=0 pw=0 time=0 us)
      0          BUFFER SORT (cr=0 pr=0 pw=0 time=0 us)
      0           PX RECEIVE  (cr=0 pr=0 pw=0 time=0 us)
      0            PX SEND BROADCAST :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
    370             VIEW  V_VNC_COD_NATURE (cr=11 pr=3 pw=0 time=4470 us)
    370              SORT ORDER BY (cr=11 pr=3 pw=0 time=4461 us)
    370               TABLE ACCESS BY INDEX ROWID VNC_CODIFICATION (cr=11 pr=3 pw=0 time=1122 us)
    370                INDEX RANGE SCAN VNC_IDE_CODIF_CODE_I (cr=3 pr=3 pw=0 time=355 us)(object id 389121)
      0      PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)
      0       TABLE ACCESS FULL ETL_BIG_TABLE (cr=0 pr=0 pw=0 time=0 us)

2) Pour le script rapide:

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
21
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.07       0.41          0          0          0           0
Execute      1      0.06      14.47          0         13       1308     2500000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.13      14.88          0         13       1308     2500000
 
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 143  (CMC_AS1)
 
Rows     Row Source Operation
-------  ---------------------------------------------------
      4  PX COORDINATOR  (cr=12 pr=0 pw=0 time=14387808 us)
      0   PX SEND QC (RANDOM) :TQ10001 (cr=0 pr=0 pw=0 time=0 us)
      0    LOAD AS SELECT  (cr=0 pr=0 pw=0 time=0 us)
      0     PX RECEIVE  (cr=0 pr=0 pw=0 time=0 us)
      0      PX SEND ROUND-ROBIN :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
      0       PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)
      0        TABLE ACCESS FULL ETL_OTHER_BIG_TABLE (cr=0 pr=0 pw=0 time=0 us)

Avez-vous déjà remarqué quelque chose dans les traces d'hier ?

D'avance, merci.

Brolon

**Waldar** · 21/12/2010, 13h32

Effectivement il y a énormément de temps CPU sur l'exécution et c'est très probablement lié aux fonctions. Est-ce qu'il est possible d'avoir les requêtes SQL ?

Vous pouvez modifier les noms d'objets si nécessaire, l'important est de conserver la logique.

**mnitu** · 21/12/2010, 14h13

Je n’aime pas les statistiques pour current et disk. Ca me fait penser à une requête qu’utilise trop d’espace temporaire. C’est quoi le paramètre workarea_size_policy ?

Comme il y a peu d’informations disponibles : nada requête, nada détails des fonctions PL/SQL, nada version d’Oracle, nada… il est assez difficile de se prononcer. De toute façon, un test simple où les fonctions PL/SQL seront remplacées par Null ou une valeur en dur devrait donner une très bonne idée sur la partie consommé par ces fonctions.

**skuatamad** · 21/12/2010, 16h22

Juste une autre précision stp.
Est ce que la table dans laquelle tu insères avec le script 1 est la même que celle avec le script 2 ?
Si non, y aurait il des différences concernant notamment les foreign keys, comme une avec l'autre sans ?
Si c'est le cas il est possible que le /*+ APPEND*/ du script 1 soit en fait ignoré, cela pourrait expliquer la grosse différence de redo dans les AUTOTRACE fournis précédemment.
Quelques lectures sur asktom à ce sujet :
http://asktom.oracle.com/pls/asktom/...:5280714813869
http://asktom.oracle.com/pls/asktom/...46503539619819

Après c'est vrai qu'il y a une grosse différence de CPU, et je ne pense pas que générer du redo soit très CPUèsque mais plutôt IOèsque, mais ça demande la confirmation de gens plus expérimentés que moi.

nada détails des fonctions PL/SQL

C'est pas vrai d'ailleurs tu lui as déjà conseillé d'utiliser CASE à la place

**mnitu** · 21/12/2010, 18h09

Envoyé par skuatamad

...C'est pas vrai d'ailleurs tu lui as déjà conseillé d'utiliser CASE à la place

Il y en a plusieurs fonctions.

**brolon** · 21/12/2010, 22h04

Désolé du manque d'imprécision dans les renseignements que je donne. Pour tenter de remédier à cela, je peux dire qu'une seule fonction est utilisée, uniquement dans le script "lent". Le code de cette fonction apparaît un peu plus haut dans le fil de discussion.

Suivant vos conseils, j'ai retiré l'affectation des colonnes alimentées via la conversion de dates ainsi que celle des colonnes alimentées via la table de codage.

La requête s'exécute en effet plus rapidement (sur un échantillon de 2500000 records, je passe de 6 min à 3 min 30 sec). Toutefois, la requête "rapide" sur un échantillon de 2500000 s'exécute en 16 sec.

Il y a donc quand même quelque chose d'autre.

Je pourrai fournir plus d'information demain lorsque je serai de retour au travail.

Merci pour vos conseils et votre patience envers le débutant que je suis ;-)

Performances et fonctions custom ?

SQL Oracle

Discussions similaires

Partager

Partager