SESSION CACHED CURSOR et Parse CPU

Version imprimable

Bonjour

Nous avons quelques pb de performances avec une base qui semble consommer bien trop de CPU et repondre lentement aux requetes des utilisateurs

Des investigations sotn en cours au niveaux rezo et systeme mais voici un AWR

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
 
Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:  100.00       Redo NoWait %:   99.97
            Buffer  Hit   %:  100.00    In-memory Sort %:  100.00
            Library Hit   %:   99.88        Soft Parse %:   99.80
         Execute to Parse %:   72.01         Latch Hit %:   98.74
Parse CPU to Parse Elapsd %:    1.56     % Non-Parse CPU:   99.97
 
 Shared Pool Statistics        Begin    End 
                              ------  ------
             Memory Usage %:   74.41   73.12
    % SQL with executions>1:   79.43   84.59
  % Memory for SQL w/exec>1:   83.17   87.31
 
Top 5 Timed Events                                         Avg %Total
~~~~~~~~~~~~~~~~~~                                        wait   Call
Event                                 Waits    Time (s)   (ms)   Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
CPU time                                          5,290          28.1           
latch: cache buffers chains         166,769       2,560     15   13.6 Concurrenc
latch: row cache objects             35,636         655     18    3.5 Concurrenc
latch free                           27,876         559     20    3.0      Other
db file sequential read              15,221         103      7    0.5   User I/O

Le parametre SESSION CACHED CURSOR est à 20
Préconiseriez vous de l'augmenter ?

25/08/2009, 17h23
farenheiit

Si le CPU Time arrive en tête des wait events c'est plutôt bon signe.
Je dirai plutôt que t'as des pb de Latch. En général, c'est dû au fait que les bind variables ne sont pas utilisées ou bien que la shared_pool est trop petite.

Est-ce le cas? depuis quand avez-vous constaté des pb de perfs? quelle est la durée sur lequel est effectué le rapport AWR ? Quelles sont les requêtes les plus consommatrices
25/08/2009, 19h37
pachot

Bonjour,
Il faudrait voir les requêtes sql qui prennent le plus de temps dans le rapport AWR.
Il n'y a pas que un problème de shared pool. 'cache buffers chains' c'est une centention sur les blocs de données.
Et au niveau OS, tout est normal ?
Cordialement,
Franck.

@farenheiit : C'est assez flou, j'ai l'impression que lors de l'installation de l'appli on a pas vraiment suivi les recommandations constructeurs. Il reste des composants a installer comme un serveur Apache

La CPU du Serv est à 100% sur toute la plage horaire des users et cette base est la plus consommatrice des 3 présentes sur le serveur (60% a elle toute seule)

Code:

1
2
3
4
5
Cache Sizes
~~~~~~~~~~~                       Begin        End
                             ---------- ----------
               Buffer Cache:       640M       640M  Std Block Size:         8K
           Shared Pool Size:       976M       976M      Log Buffer:    14,356K

Les AWR sont générés toutes les 15 Mins

Quant aux requetes une enquete est en cours coté Constructeur mais en voici deux

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
 
 
Elapsed      CPU                  Elap per  % Total              
  Time (s)   Time (s)  Executions   Exec (s)  DB Time    SQL Id    
---------- ---------- ------------ ---------- ------- -------------
     2,845        688           68       41.8    15.1 0ny2c50x9kqnw
 
 
SELECT /*+ FIRST_ROWS(200) */ rh.VISIBLE_PARAMETER42 H_OMA_DOMAI
N  ,rv.DESCRIPTION H_DESCRIPTION  ,rv.REQUEST_ID H_REQUEST_ID  ,
DECODE(rv.RT_VISIBILITY_SEC_EXISTS_FLAG,:"SYS_B_00",DECODE(kcrt_
fls_check.request_dtl_fls_check(rv.parameter_set_context_id,:"SY
S_B_01",:"SYS_B_02",:1,rv.request_id),:"SYS_B_03",TO_CHAR(KNTA_d
ata_type.to_cldate(rd2.VISIBLE_PARAMETER33), :"SYS_B_04" ),:"SYS
_B_05"),TO_CHAR(KNTA_data_type.to_cldate(rd2.VISIBLE_PARAMETER33
), :"SYS_B_06" ))  P_19e50e06  ,DECODE(rv.RT_VISIBILITY_SEC_EXIS
TS_FLAG,:"SYS_B_07",DECODE(kcrt_fls_check.request_dtl_fls_check(
rv.parameter_set_context_id,:"SYS_B_08",:"SYS_B_09",:2,rv.reques
t_id),:"SYS_B_10",TO_CHAR(KNTA_data_type.to_cldate(rv.VISIBLE_PA
RAMETER23), :"SYS_B_11" ),:"SYS_B_12"),TO_CHAR(KNTA_data_type.to
_cldate(rv.VISIBLE_PARAMETER23), :"SYS_B_13" ))  P_OMA_DEL_OLA_C
ONTRACT_DATE  ,rv.APPLICATION_MEANING H_APPLICATION_CODE  ,rv.PR
IORITY_MEANING H_PRIORITY_CODE  ,rv.CREATED_BY_NAME H_CREATED_BY
  , rv.CREATED_BY_EMAIL H_CREATED_BY_E , rv.CREATED_BY_PHONE_NUM
BER H_CREATED_BY_P , rv.CREATED_BY_USERNAME H_CREATED_BY_N  ,DEC
ODE(rv.RT_VISIBILITY_SEC_EXISTS_FLAG,:"SYS_B_14",DECODE(kcrt_fls
_check.request_dtl_fls_check(rv.parameter_set_context_id,:"SYS_B
_15",:"SYS_B_16",:3,rv.request_id),:"SYS_B_17",TO_CHAR(KNTA_data
_type.to_cldate(rd2.VISIBLE_PARAMETER31), :"SYS_B_18" ),:"SYS_B_
19"),TO_CHAR(KNTA_data_type.to_cldate(rd2.VISIBLE_PARAMETER31),
:"SYS_B_20" ))  P_OMA_WA_OLA_CONTRACT_DATE  ,rv.STATUS_NAME H_ST
ATUS_ID   FROM kcrt_requests_v rv, kcrt_request_details rd2, kcr
t_req_header_details rh WHERE (:"SYS_B_21"=:"SYS_B_22" AND (rv.b
atch_number = :"SYS_B_23" OR rv.batch_number is null)  AND (rh.P
ARAMETER26 in (:4,:5,:6,:7)) AND rv.REQUEST_TYPE_ID in (:8) AND
rv.STATUS_ID = :9  AND rv.PRIORITY_CODE = :10  AND (rd2.PARAMETE
R5 IS NULL  OR (rd2.PARAMETER5 in (:11,:12,:13)) ) AND EXISTS (S
ELECT :"SYS_B_24" from kcrt_request_dtl_fls_check_v f  WHERE f.p
arameter_column_number||:"SYS_B_25" = :"SYS_B_26" AND f.batch_nu
mber||:"SYS_B_27" = :"SYS_B_28" AND f.parameter_set_context_id =
 rv.parameter_set_context_id AND f.user_id = :14 AND f.request_i
d = rv.request_id) AND rv.REQUEST_TYPE_ID in (:15) AND exists(SE
LECT /*+ NO_UNNEST */ pcv.REQUEST_ID FROM KCRT_PARTICIPANT_CHECK
_V pcv WHERE pcv.request_id = rv.request_id and pcv.user_id = :1
6)  AND rh.request_id = rv.request_id ) AND rd2.batch_number (+)
 = :17 AND rv.REQUEST_ID = rd2.REQUEST_ID (+)  AND ROWNUM <= :"S
YS_B_29"  ORDER BY rv.REQUEST_ID DESC

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
 
  Elapsed      CPU                  Elap per  % Total              
  Time (s)   Time (s)  Executions   Exec (s)  DB Time    SQL Id    
---------- ---------- ------------ ---------- ------- -------------
 2,806        720           69       40.7    14.9 1javjy885uamq
 
 
SELECT /*+ FIRST_ROWS(200) */ rv.PRIORITY_MEANING H_PRIORITY_COD
E  ,rv.APPLICATION_MEANING H_APPLICATION_CODE  ,rh.VISIBLE_PARAM
ETER42 H_OMA_DOMAIN  ,rv.DESCRIPTION H_DESCRIPTION  ,DECODE(rv.R
T_VISIBILITY_SEC_EXISTS_FLAG,:"SYS_B_00",DECODE(kcrt_fls_check.r
equest_dtl_fls_check(rv.parameter_set_context_id,:"SYS_B_01",:"S
YS_B_02",:1,rv.request_id),:"SYS_B_03",TO_CHAR(KNTA_data_type.to
_cldate(rd2.VISIBLE_PARAMETER33), :"SYS_B_04" ),:"SYS_B_05"),TO_
CHAR(KNTA_data_type.to_cldate(rd2.VISIBLE_PARAMETER33), :"SYS_B_
06" ))  P_19e50e06  ,rv.REQUEST_ID H_REQUEST_ID  ,DECODE(rv.RT_V
ISIBILITY_SEC_EXISTS_FLAG,:"SYS_B_07",DECODE(kcrt_fls_check.requ
est_dtl_fls_check(rv.parameter_set_context_id,:"SYS_B_08",:"SYS_
B_09",:2,rv.request_id),:"SYS_B_10",TO_CHAR(KNTA_data_type.to_cl
date(rd2.VISIBLE_PARAMETER31), :"SYS_B_11" ),:"SYS_B_12"),TO_CHA
R(KNTA_data_type.to_cldate(rd2.VISIBLE_PARAMETER31), :"SYS_B_13"
 ))  P_OMA_ACKN_OLA_CONTRACT_DATE  ,rv.CREATED_BY_NAME H_CREATED
_BY  , rv.CREATED_BY_EMAIL H_CREATED_BY_E , rv.CREATED_BY_PHONE_
NUMBER H_CREATED_BY_P , rv.CREATED_BY_USERNAME H_CREATED_BY_N  ,
rv.STATUS_NAME H_STATUS_ID   FROM kcrt_requests_v rv, kcrt_reque
st_details rd2, kcrt_req_header_details rh WHERE (:"SYS_B_14"=:"
SYS_B_15" AND (rv.batch_number = :"SYS_B_16" OR rv.batch_number
is null)  AND (rh.PARAMETER26 in (:3,:4,:5,:6)) AND rv.REQUEST_T
YPE_ID in (:7) AND rv.STATUS_ID = :8  AND rv.PRIORITY_CODE = :9
 AND (rd2.PARAMETER5 IS NULL  OR (rd2.PARAMETER5 in (:10,:11,:12
)) ) AND EXISTS (SELECT :"SYS_B_17" from kcrt_request_dtl_fls_ch
eck_v f  WHERE f.parameter_column_number||:"SYS_B_18" = :"SYS_B_
19" AND f.batch_number||:"SYS_B_20" = :"SYS_B_21" AND f.paramete
r_set_context_id = rv.parameter_set_context_id AND f.user_id = :
13 AND f.request_id = rv.request_id) AND rv.REQUEST_TYPE_ID in (
:14) AND exists(SELECT /*+ NO_UNNEST */ pcv.REQUEST_ID FROM KCRT
_PARTICIPANT_CHECK_V pcv WHERE pcv.request_id = rv.request_id an
d pcv.user_id = :15)  AND rh.request_id = rv.request_id ) AND rd
2.batch_number (+) = :16 AND rv.REQUEST_ID = rd2.REQUEST_ID (+)
 AND ROWNUM <= :"SYS_B_22"  ORDER BY rv.REQUEST_ID DESC

26/08/2009, 13h37
pachot

Bonjour,

Citation:

La CPU du Serv est à 100%

Attention si la CPU du serveur est saturé (100% et runqueue > nombre de CPU) alors les indications du rapport AWR ne sont pas très utiles car des wait events vont compter le temps d'attente + le temps pour revenir en CPU (temps passé dans la runqueue) or ce dernier est une attente de CPU et n'a rien à voir avec le wait event lui même.

Les requête que tu montre, 40s pour chaque exécution, avec plein de fonctions, pas de bind variables (mais en utilisant cursor_sharing=force pour essayer de diminuer l'impact de mauvais design), etc ... sont effectivement de bonnes candidates.

Cordialement,
Franck.
26/08/2009, 13h48
farenheiit

Citation:

Envoyé par pachot

Les requête que tu montre, 40s pour chaque exécution, avec plein de fonctions, pas de bind variables (mais en utilisant cursor_sharing=force pour essayer de diminuer l'impact de mauvais design), etc ... sont effectivement de bonnes candidates.

Pourquoi dis tu "pas de bind variables" alors qu'il y'en dans ses requêtes ?
26/08/2009, 14h47
Guigsounet

@Pachot : Le pb c est que c est cette base qui semble mettre a genoux le serveur, donc si je te comprends bien nous sommes ds un cercle vicieux

La base sature le CPU, Le CPU met du temps à répondre, le AWR n'est pas utile car le CPU met du temps à répondre

Apres effectivement ces requetes semblent utiliser des Bind Variables
26/08/2009, 15h39
fatsora
Les latches ne sont que des simptomes , tu as identifié les requetes significatives.

C'est a ce niveau qu'il faut intervenir .

Ici des aides

http://oracle.developpez.com/guide/tuning/tkprof/

Sinon pour les latches
http://oracle.developpez.com/guide/tuning/latch/

avec des requetes pour identifier les objects Oracle (index ou /et tables ) incrimintés

chez Metalink : Article-ID: <Note:163424.1>

Par contre ton shared_pool est tres eleve % db_cache_size

C'est surement la conséquence de tout ce qu'on a écrit au dessus , mais faut peut etre surveiller ca aussi

voir les vues
V$SGA_TARGET_ADVICE,V$SGA_RESIZE_OPS,
v$sga_dynamic_components

Verifier que le shared_pool n'est pas surgonflé
Code:

1 2 3 4 SELECT name, bytes, pool FROM v$sgastat WHERE pool='shared pool' AND name='free memory';
Sinon quelle version oracle tu as : 10.x.x.x ?
26/08/2009, 16h02
pachot

Citation:

Envoyé par Guigsounet

@Pachot : Le pb c est que c est cette base qui semble mettre a genoux le serveur, donc si je te comprends bien nous sommes ds un cercle vicieux

La base sature le CPU, Le CPU met du temps à répondre, le AWR n'est pas utile car le CPU met du temps à répondre

Je voulais simplement dire qu'il fait se méfier en interprétant les timed events dans le rapport car ils incluent un temps d'attente de CPU.

Oui, c'est cette base qui est responsable et il fait trouver les requête qui consomment trop de CPU (souvent ce sont celles qui font trop de logical reads, mais pas seulement)

Citation:

Envoyé par Guigsounet

Apres effectivement ces requetes semblent utiliser des Bind Variables

En fait le code utilise des litérals qui sont transformés en SYS_B_ par CURSOR_SHARING=FORCE

Mais il ne semble pas que la CPU soit liée au parse:

Citation:

% Non-Parse CPU: 99.97

A vue de nez, je pense qu'il y a des requêtes sql ou du code pl/sql qui vont constamment relire les mêmes données. Je pense celà d'après les symptomes suivants:
- Buffer Hit %: 100.00, c'est un peu trop beau
- cache buffers chains, contention sur des blocs
- appels de fonctions dans la clause select
26/08/2009, 16h07
farenheiit

Citation:

En fait le code utilise des litérals qui sont transformés en SYS_B_ par CURSOR_SHARING=FORCE

Où t'as vu qu'il utilisait le curso_sharing = FORCE ?
26/08/2009, 16h10
pachot

Citation:

Envoyé par farenheiit

Où t'as vu qu'il utilisait le curso_sharing = FORCE ?

Parce que SYS_B_nn c'est la manière dont oracle nomme les bind variables dans ce cas.
26/08/2009, 16h21
farenheiit

good to know !!!
:ccool:
26/08/2009, 17h48
Guigsounet

Cursor Sharing = Similar

Ca change qqch a votre analyse ?

En tous cas merci de vos réponses :)
26/08/2009, 18h07
farenheiit

non puisque la CPU n'est pas lié au PARSE.
par contre si t'as des histogrammes sur certaines colonnes ça peut entrainer des plans d'executions instables car depuis la 9i avec le bind variable peeking, le CBO va prendre comme valeur pour les binds variables celle de la 1ère execution. Si pour la 1ère execution le CBO avait opté pour un FTS alors pour chaque requêtes similaires t'auras un FTS même si pour une autre requête un accès via index aurait été plus judicieux.
27/08/2009, 09h56
Guigsounet

Comment savoir si nous avons des histogrammes ?
27/08/2009, 11h23
fatsora

Bonjour,

tu peux regarder ces vues

DBA_TAB_HISTOGRAMS

Tables partitionnées:

DBA_PART_HISTOGRAMS
DBA_SUBPART_HISTOGRAMS

Autres vues

DBA_TAB_COL_STATISTICS
DBA_PART_COL_STATISTICS
DBA_SUPPART_COL_STATISTICS

les histogrammes sont générés par les stats

http://download.oracle.com/docs/cd/B...ats.htm#i42219

a partir de 10G si tu a laissé par défaut le SCHEDULE de stats alors tu devrais avoir des histogrammes sur certaines tables de certaines colones

Par contre le CURSOR_SHARING=SIMILAR

Peut causer beaucoup de problemes

http://arkzoyd.blogspot.com/2008/04/...hodoptfor.html

et il a des bug reférences sur ce sujet chez metalink ainsi que des comprtements inattentus

http://kr.forums.oracle.com/forums/t...hreadID=658310

Donc faire attention que les problemes resolus ne soient inférieurs aux problemes apportés par le SIMILAR

Il ne suffit pas de regarder dans DBA_TAB_HISTOGRAMS, il faut que le nombre de lignes par colonne soit > 2:

Code:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
 
SQL> select	sum(case when max_cnt > 2 then 1 else 0 end) histograms,
  2  		sum(case when max_cnt <= 2 then 1 else 0 end) no_histograms
  3  from (
  4  	select table_name, max(cnt) max_cnt
  5  		from (
  6  			select table_name, column_name, count(*) cnt
  7  				from dba_tab_histograms
  8  				group by table_name, column_name
  9  		) group by table_name
 10  );
 
HISTOGRAMS NO_HISTOGRAMS
---------- -------------
       304           521

Code:

1
2
3
HISTOGRAMS NO_HISTOGRAMS
---------- -------------
301             335

28/08/2009, 09h44
farenheiit

Il faut tuner les requêtes les plus consommatrices une par une