Bonjour,

Une application DELPHI /Oracle 9.2 tourne actuellement sur un poste classique de façon correcte. Tout est sur le même serveur (application delphi + serveur oracle). Le poste est sous Windows XP.

Cette même application a été placé sur un nouveau serveur plus performant (XEON 3ghz double coeur, disques durs SCSI en RAID 1, sous windows 2003...) et les performances lors de l'exécution d'un traitement ont été divisé par 3/4 ce qui n'est pas acceptable.

On m'a chargé de détecter les causes de cette mauvaise performance.
Pendant les tests, il a été détecté qu'un seul coeur du processeur sur les 2 est utilisé par l'application en delphi ainsi que le serveur oracle. Cependant, cela ne semble pas être ce qui bride les performances puisque le processeur est rarement à 50 % (50% représentant la totalité de l'un des deux coeurs)

Un bench des disques dur a montré que les performances sont acceptables.

Une analyse des traces oracle du traitement avec TKPROF (800mo de traces oracle) donne les résultats suivants (certaines requêtes ont été enlevées pour que ce soit moins long) qui sont très étonnants au niveau du elapsed time du FETCH du "OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS", tout en bas

Le traitement dure de l'ordre de 24h au lieu de 5-6 heures sur l'ancien serveur.

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
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
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
TKPROF: Release 9.2.0.6.0 - Production on Wed Dec 19 18:11:28 2007

Copyright (c) 1982, 2002, Oracle Corporation.  All rights reserved.

Trace file: s2008_ora_4140.trc
Sort options: prscpu  execpu  fchcpu  
********************************************************************************
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
********************************************************************************

select d.id_fiche_sncf,r.id as idRep
from 
dem_fiche d,
dem_pr dr,
rep_fiche r,
rep_pr pr 
where r.Liste_id_fiche_sncf is null 
and r.parite is null 
and d.id = dr.id_fiche 
and r.id = pr.id_fiche
and pr.ci_pr=dr.ci_pr
and pr.ch_pr=dr.ch_pr
and (( r.num_sillon_reponse = d.num_sillon1 ) 
or ( r.num_sillon_reponse = d.num_sillon2 ))
and d.id_fiche_sncf like :1
and not exists (select id_rep_fiche from correspondance where id_rep_fiche = r.id)
and ((dr.heure_local_dep is null and pr.heure_local_dep is null 
and dr.heure_local_arr is not null and pr.heure_local_arr is not null)
or (dr.heure_local_arr is null and pr.heure_local_arr is null 
and dr.heure_local_dep is not null and pr.heure_local_dep is not null))
and ((abs(to_number(dr.heure_local_arr) - to_number(pr.heure_local_arr)) <= :2)
or (abs(to_number(dr.heure_local_dep) - to_number(pr.heure_local_dep)) <= :3))

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        5      0.00       0.01          0          0          0           0
Execute      5      0.00       0.00          0          0          0           0
Fetch       15   1158.25    1318.85      93922    1156005          0        1565
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       25   1158.25    1318.87      93922    1156005          0        1565

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 23  

Rows     Row Source Operation
-------  ---------------------------------------------------
    134  FILTER  
  16734   NESTED LOOPS  
  61193    HASH JOIN  
 949001     TABLE ACCESS BY INDEX ROWID REP_PR 
 980877      NESTED LOOPS  
  31875       TABLE ACCESS FULL REP_FICHE 
 949001       INDEX RANGE SCAN IX_REP_PR_01 (object id 7032)
 322033     TABLE ACCESS FULL DEM_PR 
  16734    TABLE ACCESS BY INDEX ROWID DEM_FICHE 
  61193     INDEX UNIQUE SCAN PK_DEM_FICHE (object id 6866)
  15177   INDEX RANGE SCAN IX_CORRESPONDANCE_02 (object id 7028)

********************************************************************************

update Dem_Fiche set Traite = :1 
where
 No_Demande_Rff = :2


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse    35285      0.68       0.56          0          0          0           0
Execute  35285     64.84      65.57        110     105973     178489       35285
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total    70570     65.53      66.14        110     105973     178489       35285

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 23  

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  UPDATE  
      1   TABLE ACCESS BY INDEX ROWID DEM_FICHE 
      1    INDEX RANGE SCAN IX_DEM_FICHE_03 (object id 6869)

********************************************************************************

ANALYZE TABLE REP_PR COMPUTE STATISTICS


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1     62.51      90.82      31219      36093         30           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2     62.51      90.82      31219      36093         30           0

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 23  
********************************************************************************

INSERT INTO Correspondance
  (Id, Id_Dossier, Id_Rep_Fiche,CAS)
VALUES
  (Sq_Correspondance_01.NEXTVAL, :1, :2,:3)

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse    40544      0.57       0.64          0          0          0           0
Execute  40544     26.31      30.84        380      42258     550101       40544
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total    81088     26.89      31.48        380      42258     550101       40544

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 23  

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  SEQUENCE  

********************************************************************************

update dem_fiche set traite=null


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0         43          0           0
Execute      1     25.82      29.25         62       8336     166676       47470
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2     25.82      29.25         62       8379     166676       47470

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 23  

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  UPDATE  
  47470   TABLE ACCESS FULL DEM_FICHE 

********************************************************************************

INSERT INTO Ecart
  (Id,
   Id_Fiche_Sncf,
   Rang,
   Id_Fiche_Rep,
   Id_Pr_Rep,
   Type_Ecart,
   Description)
VALUES
  (Sq_Ecart_01.NEXTVAL,
   :1,
   :2,
   :3,
   :4,
   :5,
   :6)

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse    30988      0.40       0.42          0          5          0           0
Execute  30988     17.92      18.58         34      31408     348505       30988
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total    61976     18.32      19.01         34      31413     348505       30988

Misses in library cache during parse: 1
Misses in library cache during execute: 2
Optimizer goal: CHOOSE
Parsing user id: 23  

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  SEQUENCE  

********************************************************************************

select Heure_Local_Arr, Heure_Local_Dep, Ci_Pr
  from Dem_Pr
 where Rang = :1
   and Id_Fiche = :2

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse   177926      3.29       2.35          0          0          0           0
Execute 177926      5.85       5.38          0          0          0           0
Fetch   355852      6.98      23.29       4359     889629          0      177926
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   711704     16.14      31.03       4359     889629          0      177926

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 23  

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  TABLE ACCESS BY INDEX ROWID DEM_PR 
      1   INDEX RANGE SCAN IX_DEM_PR_01 (object id 6876)

********************************************************************************

ANALYZE TABLE DEM_PR COMPUTE STATISTICS


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1     11.42      12.67       1686       6175          8           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2     11.42      12.67       1686       6175          8           0

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 23  
********************************************************************************



********************************************************************************

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse   780651     13.09      11.46          3        138          0           0
Execute 780651    270.87     337.93      62476     661420    2080424      298576
Fetch   1000494   1191.574154500164.68     155322    3913556         15      686045
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   2561796   1475.544154500514.08     217801    4575114    2080439      984621

Misses in library cache during parse: 61
Misses in library cache during execute: 3


OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse   287495      5.12       4.79          6        278          0           0
Execute 590483     35.32      48.31       2437     327949     284873      161652
Fetch   435566     10.51      55.24      12000    1474151          2      435124
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   1313544     50.96     108.35      14443    1802378     284875      596776

Misses in library cache during parse: 134
Misses in library cache during execute: 2

994853  user  SQL statements in session.
73295  internal SQL statements in session.
1068148  SQL statements in session.
********************************************************************************
Trace file: s2008_ora_4140.trc
Trace file compatibility: 9.02.00
Sort options: prscpu  execpu  fchcpu  
       1  session in tracefile.
  994853  user  SQL statements in trace file.
   73295  internal SQL statements in trace file.
  1068148  SQL statements in trace file.
     191  unique SQL statements in trace file.
 14728913  lines in trace file.
Est-ce que vous avez une explication de ce fetch énorme ? (d'ailleurs les valeurs sont si grandes que cela ne peut pas être possible)

A quoi correspond exactement le "OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS" ?

Code : Sélectionner tout - Visualiser dans une fenêtre à part
1
2
3
4
5
6
7
8
9
10
11
********************************************************************************

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse   780651     13.09      11.46          3        138          0           0
Execute 780651    270.87     337.93      62476     661420    2080424      298576
Fetch   1000494   1191.574154500164.68     155322    3913556         15      686045
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   2561796   1475.544154500514.08     217801    4575114    2080439      984621



je n'ai pas la main sur le serveur. Avant que je puisse faire de nouvelles demandes de test, je dois avoir une piste sérieuse...

Merci pour votre aide!