Performance LOB

Version imprimable

16/05/2006, 13h03
Wurlitzer

Performance LOB
J'ai une appli qui fait beaucoup (énormément) de Buffer Gets. Cette appli utilise beaucoup de LOB. Avec un algo du style :
Code:

1 2 3 4 5 6 7 BOUCLE Creation LOB Temporaire Replissage du LOB par xmldom Passage du LOB a une procédure stocké (Insertion du LOB) Suppresion du LOB Temporaire FIN DE BOUCLE
J'ai fait des tests pour essayer d'optimiser :
- J'ai essayé de sortir la création/suppression du LOB temporaire de la boucle et de le reinitialiser par un TRIM
- J'ai essayé de mettre les paramètres de la proc stock en NOCOPY
Cela ne change apparement rien, je ne vois aucune différence sur le tkrpof. Peut etre que je ne regarde pas du bon coté.

Avez vous des idées pour expliquer cela ? Et d'autres choses que je pourrais tester

Merci,
16/05/2006, 14h19
orafrance

qu'est ce qui te fait croire que les buffer gets viennent bien de l'usage des LOB ?
16/05/2006, 14h25
Wurlitzer

Rien, je cherche...

Tout ce que je sais c'est qu'ils ne viennent pas d'un ordre SQL.

Dans le tkprof

J'ai ma proc stocké en premier avec beaucoup de Buffer Gets et de CPU.

Et le premier order SQL beaucoup, beaucoup plus bas (environ 1%)

Le total est proche de ce qui est consommé par la proc stocké.

J'ai cherché du coté de Java, je cherche maintenant du coté des LOB mais je suis dans le flou.

Je suis aussi preneur d'une methode pour trouver ce que fait un code PL/SQL quand il ne fait pas de SQL.

Citation:

Envoyé par Wurlitzer

J'ai cherché du coté de Java, je cherche maintenant du coté des LOB mais je suis dans le flou.

C'est justement ça le problème, on optimise pas une base en cherchant la cause au petit bonheur la chance :?
Essaye donc d'utiliser statpack et ainsi déterminer avec plus d'efficacité les points problèmatiques de ta base et mieux appréhendre leurs causes ;)

Regarde un peu la doc aussi : http://download-west.oracle.com/docs...trac.htm#16050 ou http://download-west.oracle.com/docs...mory.htm#45098 ça devrait t'aiguiller sur la manière d'appréhender le "problème" si problème il y a ;)

Essaye ceci :
Code:

1 2 3 4 5 6 7 8 9 column per_exec format 999,999,999 column buffer_gets format 999,999,999 select buffer_gets, executions, buffer_gets/executions per_exec, substr(sql_text,1,4000) SQL from v$sqlarea where executions > 1 and buffer_gets/executions > 10000 order by buffer_gets/executions desc /
Et oriente tes recherches sur db_block_lru_latches ou DB_CACHE_ADVICE ;)

Citation:

Envoyé par Wurlitzer

Je suis aussi preneur d'une methode pour trouver ce que fait un code PL/SQL quand il ne fait pas de SQL.

j'ai pas compris :(

Je n'ai pas fait tout l'historique mais je suis parti de statspack qui me donne beaucoup de "db file sequential read "

Je regarde donc les Top SQL et je trouve un package qui fait des millions de Buffer Gets

Je met alors ce package en mode Trace et j'obtiens un tkprof du style

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
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
 
TKPROF: Release 8.1.7.4.0 - Production on Je Mai 11 16:49:15 2006
 
(c) Copyright 2000 Oracle Corporation.  All rights reserved.
 
Trace file: ora_11646_soins.trc
Sort options: exeela  fchela  
********************************************************************************
count    = number of times OCI procedure was executed
cpu      = cpu time in seconds executing 
elapsed  = elapsed time in seconds executing
disk     = number of physical reads of buffers from disk
query    = number of buffers gotten for consistent read
current  = number of buffers gotten in current mode (usually for update)
rows     = number of rows processed by the fetch or execute call
********************************************************************************
 
begin 
pkg_toto.setnextmessage; 
end;
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        2      0.00       0.03          0          0          0           0
Execute      1     13.67      27.85          0        926      10118           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3     13.67      27.88          0        926      10118           1
 
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 52  
********************************************************************************
select longname
from
 javasnm$ where short = :1
 
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute  69678      0.96       0.76          0          0          0           0
Fetch    69678      1.43       1.22          0     278712          0       69678
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   139357      2.39       1.98          0     278712          0       69678
 
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS   (recursive depth: 1)
 
INSERT INTO MA_TABLE (COL1,etc )  
VALUES
 ( :b1,etc  )
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.01          0          1          0           0
Execute    229      0.07       1.88        296         13       6509         229
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total      230      0.07       1.89        296         14       6509         229
 
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer goal: CHOOSE
Parsing user id: 52    (recursive depth: 1)
error during parse of EXPLAIN PLAN statement
ORA-00942: table or view does not exist

Suivit d'autres ordres SQL insignifiant aussi bien au niveau CPU que query et current

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
 
 
 
********************************************************************************
 
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        2      0.00       0.03          0          0          0           0
Execute      1     13.67      27.85          0        926      10118           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3     13.67      27.88          0        926      10118           1
 
Misses in library cache during parse: 1
 
 
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse      371      0.11       0.16          1          8          1           0
Execute  76098      1.18       2.79        303       1152      10350         554
Fetch    76387      1.82       1.81         31     327622       4671       75078
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   152856      3.11       4.76        335     328782      15022       75632
 
Misses in library cache during parse: 80
Misses in library cache during execute: 2
 
  282  user  SQL statements in session.
   91  internal SQL statements in session.
  373  SQL statements in session.
   44  statements EXPLAINed in this session.
********************************************************************************
Trace file: ora_11646_soins.trc
Trace file compatibility: 8.00.04
Sort options: exeela  fchela  
       1  session in tracefile.
     282  user  SQL statements in trace file.
      91  internal SQL statements in trace file.
     373  SQL statements in trace file.
      81  unique SQL statements in trace file.
      44  SQL statements EXPLAINed using schema:
              Default table was used.
             Table was created.
             Table was dropped.
  155790  lines in trace file.

Mon problème est donc de savoir ce que fait pkg_toto.setNextMessage. Au niveau de la trace je ne sais pas comment faire pour avoir plus d'information au niveau du code j'ai vu qu'il faisait de Java (xmldom) et qu'il utilisait de CLOB. Voila pourquoi je cherche de ce coté.

Ma démarche est elle bonne ? Comment est ce que je pourrais aller plus loin ?

Merci de votre aide

16/05/2006, 16h56
orafrance

Mais attend... si le volume sélectionné est important (à cause des LOB) c'est normal d'avoir beaucoup de buffer gets aussi... il faut peut-être s'intéresser à la taille des blocs dans ce cas. Mais tu as des problèmes de perf ? Parce que des attentes sur "db file sequential read" c'est pas ce qui m'inquiterait le plus moi ;)
16/05/2006, 17h08
Wurlitzer

Oui j'ai bien des problèmes de perfs et c'est bien les 'db sequential read' qui m'inquietent. Je ne cherche pas du bon coté ?

Il faut que je ne m'interesse exclusivement au Top SQL par Physical Read et pas a ceux par Buffer Gets ? 8O
16/05/2006, 17h11
orafrance

envoie donc le début de ton rapport statpack, regardes aussi du coté de v$session_wait et v$system_event. DB_SEQUENTIAL_READ c'est de la lecture d'index, donc c'est pas forcément un problème de la base mais plutôt de performance disque et/ou d'exhaustivité des données.

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
50
51
52
53
54
55
56
57
58
59
60
61
62
63
 
STATSPACK report for
 
DB Name         DB Id    Instance     Inst Num Release     OPS Host
------------ ----------- ------------ -------- ----------- --- ------------
XXXXX         2996321625 XXXXX               1 8.1.7.4.0   NO  host
 
                Snap Id     Snap Time      Sessions
                ------- ------------------ --------
 Begin Snap:                          3144 15-Mai-06 08:09:04      261
   End Snap:                          3156 15-Mai-06 14:11:03      261
    Elapsed:                             361.98 (mins)
 
Cache Sizes
~~~~~~~~~~~
           db_block_buffers:     160000          log_buffer:
   1048576
              db_block_size:       8192    shared_pool_size:
 550000000
 
Load Profile
~~~~~~~~~~~~                            Per Second       Per Transaction
                                   ---------------       ---------------
                  Redo size:            102,723.91              5,924.23
              Logical reads:             25,046.35              1,444.46
              Block changes:                713.94                 41.17
             Physical reads:                547.75                 31.59
            Physical writes:                 47.70                  2.75
                 User calls:              1,236.13                 71.29
                     Parses:                335.16                 19.33
                Hard parses:                  1.28                  0.07
                      Sorts:                 70.11                  4.04
                     Logons:                  1.21                  0.07
                   Executes:              1,349.71                 77.84
               Transactions:                 17.34
 
  % Blocks changed per Read:    2.85    Recursive Call %:               77.39
 Rollback per transaction %:    1.56       Rows per Sort:               96.54
 
Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:   99.99       Redo NoWait %:              100.00
            Buffer  Hit   %:   97.81    In-memory Sort %:               99.99
            Library Hit   %:   99.93        Soft Parse %:               99.62
         Execute to Parse %:   75.17         Latch Hit %:               99.90
Parse CPU to Parse Elapsd %:   76.01     % Non-Parse CPU:               99.97
 
 Shared Pool Statistics        Begin   End
                               ------  ------
             Memory Usage %:   87.38   80.41
    % SQL with executions>1:   38.81   60.05
  % Memory for SQL w/exec>1:   46.93   70.06
 
Top 5 Wait Events
~~~~~~~~~~~~~~~~~                                             Wait     % Total
Event                                               Waits  Time (cs)   Wt Time
-------------------------------------------- ------------ ------------ -------
db file sequential read                         6,687,053    4,865,342   51.14
PL/SQL lock timer                                  60,404    3,296,187   34.65
db file scattered read                            894,851      604,626    6.36
log file parallel write                           330,236      264,135    2.78
SQL*Net message from dblink                        84,941      174,751    1.84
          -------------------------------------------------------------

16/05/2006, 18h04
orafrance

ça a l'air de tourner comme une horloge :koi:

qu'ont données tes investigations sur v$session_wait ? Tu as des problèmes de perf bien localisés ou c'est général ?

Calcul le taux de lecture des fichiers en divisant le temps par le nombre de bloc STP et donne nous le résultat ;)
16/05/2006, 19h12
Wurlitzer

Ouurah ! ! ! :D

Dans le paragraphe : Why is Performance Affected When Temporary LOBs are Created in a Called Routine? de
http://www.lc.leidenuniv.nl/awcourse...faq.htm#123679

Ils expliquent un truc. J'avoue sincèrement que je n'ai pas bien compris mais cela correspond a mon cas. J'ai fais des tests unitaires et ca l'air radicale. Il me reste plus qu'a tester cela grandeur nature.

Merci à tous
16/05/2006, 20h28
orafrance

8O ça alors... voila qui est très intéressant :bravo:

si j'ai bien compris, il suffit de créer un LOB temporaire dans une variable de package au lieu d'une variable locale c'est bien ça ?
17/05/2006, 08h26
Wurlitzer

C'est ce que j'ai compris et que j'ai constaté aussi parce que c'est apparament la création du contexte qui est couteuse et que cette création est lié a la duré de vie de la variable et non pas a chaque appel de DBMS_LOB.CreateTemporary comme on (je) pouvais le croire.