statspack: cpu time et elapsed

Version imprimable

Bonjour à tous,
j'ai ci-dessous un extrait de statspack et je suis surpris de voir que le requête ne consomme que 55s de cpu alors qu'elle dure 1837s !
Il n'y a pas de w i/o (enfin très peu), est ce que cela peut-être du à un verrou ? ? j'y crois pas trop mais je ne sais que penser !

Code:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
 
 
 
 
                                                     CPU      Elapsd
  Buffer Gets    Executions  Gets per Exec  %Total Time (s)  Time (s) Hash Value
--------------- ------------ -------------- ------ -------- --------- ----------
      2,215,880       15,394          143.9    6.1    55.18   1875.37  221651136
 
Module: /logi/hraccess50/zf9/bin/RTSDGN@nyplsacc (TNS V1
select NUDOSS  ,SOCDOS  ,NULIGN  ,TO_CHAR(DATABS,'YYYY-MM-DD')
,MOTABS  ,CDAXES  ,NUMDRO  ,TO_CHAR(DATDEB,'YYYY-MM-DD')  ,NUMTR
A  ,TO_CHAR(DATFIN,'YYYY-MM-DD')  ,TEMDEB  ,TEMFIN  ,UNITE1  ,UN
ITE2  ,NBRJOU  ,SALRF  ,SALRFD  ,SALRFX  ,TEMDEC  ,ZONEUT  ,TO_C
HAR(DATEAG,'YYYY-MM-DD')  ,VALIDE   from ZYDA where (NUDOSS=:b1

16/09/2009, 09h50
pachot

Bonjour,

Peut être la partie 'top timed event' peut te donner une indication si le temps elapsed de la requête (1875s) est representatif par rapport au DB time total.
Elapsed-CPU, ce peut être n'importe quel wait event.

Ces 15000 executions, si elles sont en parallèle, elle touchent peut être aux mêmes blocks.

Cordialement,
Franck.

top 5 timed events

Merci pour ta réponse.
Si il y a des wait, cela veut dire qu'il y a des mises à jour sur la table ? Je ne vois pas quel wait il peut y avoir s'il n'y a que des select ...
En top 5 j'ai l'événement db file sequential read qui est largement en tête. De ce que j'ai compris, cet évènement correspond à la lecture de tables via index.

Code:

1
2
3
4
5
6
7
8
9
Top 5 Timed Events
~~~~~~~~~~~~~~~~~~                                                     % Total
Event                                               Waits    Time (s) Ela Time
-------------------------------------------- ------------ ----------- --------
db file sequential read                         1,961,887      14,623    91.86
CPU time                                                        1,056     6.64
log file sync                                      15,534         122      .77
log file parallel write                            16,157          91      .57
buffer busy waits                                     348          13      .08

16/09/2009, 14h53
pachot

Bonjour,

Donc la question initiale était de comprendre pourquoi la requête avait utilisé 55s de CPU durant un temps de 1837s (donc 3%)
On voit que c'est à peu près le même ratio au niveau de l'instance. Et donc probablement la différence provient du temps d'i/o (db file sequential read)

Tu précisais qu'il y avait très peu de wait i/o

D'après le top 5, on peut calculer le temps moyen par i/o: 14623 /1961887 = 7,45 millisecondes par i/o
Celà ne parait pas anormal pour des lectures aléatoires (ce qui est en principe le cas des 'db file sequential read') donc je ne suis pas surpris qu'il n'y ait pas de wait i/o

Si tu pense qu'il y a quelque chose à améliorer, il faudrait alors que la requête fasse moins d'i/o -> voir le plan d'execution, ou le buffer cache.
Mais en soi, ce n'est pas anormal qu'une base de donnée fasse des i/o ;)

Cordialement,
Franck.
21/09/2009, 17h54
mongolic

clustering factor

merci pour ta réponse,

Effectivement c'était normal qu'il fasse autant d'i/o. La table avait besoin d'être réorganisé.
j'ai réussi à diviser par trois les i/o en réorganisant la table pour réduire le clustering_factor.

merci
21/09/2009, 18h20
pachot

Cool ;)