jeudi 15 mars 2012

Problème de performances avec un UPDATE

Un problème de performance m’a été remonté cette semaine sur une procédure stockée qui consiste à enchainer une série d’updates telles que celle-ci-dessous :
UPDATE CALC_PRELOAD_DECADEDOWN 
   SET (STRAT_LIQUIDITY) = 
       (SELECT DDN_STRAT_LIQUIDITY 
          FROM VMUT_DECADEDOWN, MUT_OBJECTS 
         WHERE OBJ_ID = DDN_ID 
           AND OBJ_PARENT_ID = TIT_ID) 
 WHERE SESSION_ID = :B3 
   AND LYX_DAY = :B2 
   AND SCE_ID = :B1 ; 

Cet update s'exécute en 45 minutes environ.
Comme la procédure est composée de plusieurs requêtes de ce type là, son exécution totale met plus de 7 heures.
Pour pouvoir reproduire l’exécution de l’update il m’a d’abord fallu récupérer la valeur des binds variables :B3, :B2 et :B1. Pour ce faire on peut utiliser la vue v$sql_bind_capture de la manière suivante :
col VALUE_STRING for A20 
select name,position,datatype_string,value_string 
from v$sql_bind_capture where sql_id='80x62t50u2z28';              
NAME                             POSITION DATATYPE_STRING VALUE_STRING 
------------------------------ ---------- --------------- -------------------- 
:B3                                     1 VARCHAR2(128)   1329633681977 
:B2                                     2 DATE            02/15/12 00:00:00 
:B1                                     3 NUMBER          926082116

La colonne VALUE_STRING nous donne les valeurs des binds variables récupérées par Oracle lors de la première exécution de la requête (voir Bind Variable peeking).
Pour reproduire le problème de lenteur il suffit de remplacer dans la requête les binds variables par les valeurs ci-dessus :
UPDATE CALC_PRELOAD_DECADEDOWN 
   SET (STRAT_LIQUIDITY) = 
       (SELECT DDN_STRAT_LIQUIDITY 
          FROM VMUT_DECADEDOWN, MUT_OBJECTS 
         WHERE OBJ_ID = DDN_ID 
           AND OBJ_PARENT_ID = TIT_ID) 
 WHERE SESSION_ID = '1329460869262' 
   AND LYX_DAY = to_date('02/15/12','MM/DD/YY') 
   AND SCE_ID = 926082116; 

47289 rows updated. 

Elapsed: 00:44:17.32 

SQL> @plan_last 

Plan hash value: 2387757449 
--------------------------------------------------------------------------------------------------------------------------------- 
| Id  | Operation                     | Name                         | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  | 
--------------------------------------------------------------------------------------------------------------------------------- 
|   0 | UPDATE STATEMENT              |                              |      1 |        |      0 |00:43:11.49 |    2464K|    622K| 
|   1 |  UPDATE                       | CALC_PRELOAD_DECADEDOWN      |      1 |        |      0 |00:43:11.49 |    2464K|    622K| 
|*  2 |   TABLE ACCESS BY INDEX ROWID | CALC_PRELOAD_DECADEDOWN      |      1 |    126 |  47289 |00:00:04.28 |   41510 |   2085 | 
|*  3 |    INDEX RANGE SCAN           | PK_PRELOAD_DECADOWN_BY_TYPE1 |      1 |    126 |  47289 |00:00:01.06 |     357 |    355 | 
|   4 |   NESTED LOOPS                |                              |  47289 |      6 |  16708 |00:43:03.75 |    2341K|    620K| 
|   5 |    TABLE ACCESS BY INDEX ROWID| MUT_OBJECTS                  |  47289 |      6 |   1227K|00:42:41.11 |    1097K|    620K| 
|*  6 |     INDEX RANGE SCAN          | IDX_PARENT_ID                |  47289 |      4 |   1227K|00:00:06.45 |     145K|     89 | 
|   7 |    TABLE ACCESS BY INDEX ROWID| MUT_DECADEDOWN               |   1227K|      1 |  16708 |00:00:20.01 |    1243K|      0 | 
|*  8 |     INDEX UNIQUE SCAN         | PK_MUT_DECADEDOWN            |   1227K|      1 |  16708 |00:00:14.27 |    1227K|      0 | 
--------------------------------------------------------------------------------------------------------------------------------- 
Predicate Information (identified by operation id): 
--------------------------------------------------- 
   2 - filter("SCE_ID"=:SYS_B_3) 
   3 - access("SESSION_ID"=TO_NUMBER(:SYS_B_0) AND "LYX_DAY"=TO_DATE(:SYS_B_1,:SYS_B_2)) 
   6 - access("OBJ_PARENT_ID"=:B1) 
   8 - access("OBJ_ID"="DDN_ID") 

Note 
----- 
   - cpu costing is off (consider enabling it) 

On s’aperçoit que la requête a mis 44 minutes pour modifier 47289 lignes dans la table CALC_PRELOAD_DECADEDOWN.

En regardant le plan à partir de l’opération 4, on voit que le NESTED LOOP, qui correspond à la sous requête de l’update, génère 2.4 millions de logical reads. Une moitié de ces logical reads pour accéder à la table MUT_OBJECTS via l’index IDX_PARENT_ID et l’autre moitié pour accéder à la table MUT_DECADEDOWN via l’index PK_MUT_DECADEDOWN.

La colonne STARTS du plan pour l’opération 4 indique que le NESTED LOOP est exécuté 47289 fois. Ceci s’explique par le fait que l’update modifie 47289 lignes et donc pour chaque ligne modifiée Oracle doit exécuter la sous-requête. C’est ce qui explique le problème de performance pour cette requête. En effet, lorsque vous avez une sous requête qui est appelée pour déterminer la valeur de la ou des colonnes à modifier il faut avoir à l’esprit que cette sous requête sera appelée autant de fois qu’il y’a de lignes à modifier.

Comme cet update n’est qu’une requête parmi beaucoup d’autres dans la procédure appelée et que quasiment toutes les requêtes d’update se basent sur la jointure entre MUT_OBEJCTS et MUT_DECADEDOWN, la solution que j’ai adopté consiste à stocker le résultat de la jointure entre ces 2 tables au début de la procédure dans une table temporaire et d’appeler la table temporaire dans la sous requête. Le résultat de la jointure est ainsi matérialisé dans une table temporaire ce qui évite d’avoir à effectuer la jointure N fois (N étant le nombre de lignes modifiées par l’ensemble des requêtes de la procédure).

Appliquons le principe de la table temporaire à ma requête précédente
SQL> create global temporary table TMP_MUT_OBJECTS1 on commit delete rows 
  2  as 
  3  SELECT  ddn.*, obj.OBJ_PARENT_ID "OBJ_PARENT_ID" 
  4  FROM VMUT_DECADEDOWN ddn, MUT_OBJECTS obj 
  5  where 1=2; 

Table created. 

Elapsed: 00:00:00.20 

SQL> create index IDX_TMP_MUT_OBJECTS1 on TMP_MUT_OBJECTS1(OBJ_PARENT_ID); 

Index created. 

Elapsed: 00:00:00.03 

SQL>  Insert into TMP_MUT_OBJECTS1 SELECT  ddn.*, obj.OBJ_PARENT_ID 
  2  FROM VMUT_DECADEDOWN ddn, MUT_OBJECTS obj 
  3  where obj.OBJ_ID = ddn.DDN_ID; 

19344 rows created. 

Elapsed: 00:00:37.87 


L’insert dans ma table temporaire ne m’a coûté que 37 secondes.
Maintenant exécutons l’update avec la table temporaire remplaçant la jointure :
SQL> UPDATE CALC_PRELOAD_DECADEDOWN 
  2     SET (STRAT_LIQUIDITY) = 
  3         (SELECT DDN_STRAT_LIQUIDITY 
  4            FROM TMP_MUT_OBJECTS1         WHERE OBJ_PARENT_ID = TIT_ID) 
  5   WHERE SESSION_ID = '1329460869262' 
  6     AND LYX_DAY = to_date('02/15/12','MM/DD/YY') 
  7     AND SCE_ID = 926082116; 

47289 rows updated. 

Elapsed: 00:00:00.88 

Plan hash value: 999872190 
----------------------------------------------------------------------------------------------------------------------- 
| Id  | Operation                    | Name                         | Starts | E-Rows | A-Rows |   A-Time   | Buffers | 
----------------------------------------------------------------------------------------------------------------------- 
|   0 | UPDATE STATEMENT             |                              |      1 |        |      0 |00:00:00.83 |     186K| 
|   1 |  UPDATE                      | CALC_PRELOAD_DECADEDOWN      |      1 |        |      0 |00:00:00.83 |     186K| 
|*  2 |   TABLE ACCESS BY INDEX ROWID| CALC_PRELOAD_DECADEDOWN      |      1 |    126 |  47289 |00:00:00.09 |   40968 | 
|*  3 |    INDEX RANGE SCAN          | PK_PRELOAD_DECADOWN_BY_TYPE1 |      1 |    126 |  47289 |00:00:00.01 |     357 | 
|   4 |   TABLE ACCESS BY INDEX ROWID| TMP_MUT_OBJECTS1             |  47289 |    179 |  16708 |00:00:00.26 |   64268 | 
|*  5 |    INDEX RANGE SCAN          | IDX_TMP_MUT_OBJECTS1         |  47289 |     72 |  16708 |00:00:00.18 |   47560 | 
----------------------------------------------------------------------------------------------------------------------- 
Predicate Information (identified by operation id): 
--------------------------------------------------- 
   2 - filter("SCE_ID"=:SYS_B_3) 
   3 - access("SESSION_ID"=TO_NUMBER(:SYS_B_0) AND "LYX_DAY"=TO_DATE(:SYS_B_1,:SYS_B_2)) 
   5 - access("OBJ_PARENT_ID"=:B1) 

L’update s’exécute instantanément.
On est passé de 2.4 millions de logical reads à seulement 186K.
Cette méthode appliqué à l’ensemble des updates de la procédure stockée a fait passer l’exécution du traitement de 7h à seulement une dizaine de minutes.