Elapsed time for Stored Procedure and Time model

From: thierry gascard <tgascard_at_gmail.com>
Date: Thu, 29 Sep 2011 09:39:48 +0200
Message-ID: <CAJrMwWR8qOVpst7LTan=uYnxsyGAoDASLZT7ROc5chUDFWREwQ_at_mail.gmail.com>

Hello;
I try to understand why so much elapsed times with a stored procedure 124,037 s elapsed time against 968 s of Cpu time. There isn't very much SQL activity, but with Time Model Statistics this 89.5 % of DB Time !!!

An extract of AWR report :

              Snap Id      Snap Time      Sessions Curs/Sess
            --------- ------------------- -------- ---------
Begin Snap:     25358 26-Sept.-11 19:45:2       20       8.6
  End Snap:     25402 27-Sept.-11 06:45:4       19       6.0
   Elapsed:              660.28 (mins)
   DB Time:            2,725.23 (mins)

...

Time Model Statistics DB/Inst: MACSTP/MACSTP Snaps: 25358-25402
-> Total time in database user-calls (DB Time): 163514s
-> Statistics including the word "background" measure background process

   time, and so do not contribute to the DB time statistic
-> Ordered by % or DB time desc, Statistic name

Statistic Name                                       Time (s) % of DB Time
------------------------------------------ ------------------ ------------
sql execute elapsed time                            146,340.9         89.5
PL/SQL execution elapsed time                        43,324.9         26.5
inbound PL/SQL rpc elapsed time                      30,334.5         18.6
parse time elapsed                                    4,442.9          2.7
DB CPU                                                2,304.0          1.4
hard parse elapsed time                                 123.7           .1
PL/SQL compilation elapsed time                           8.1           .0
connection management call elapsed time                   5.6           .0
repeated bind elapsed time                                1.7           .0
hard parse (sharing criteria) elapsed time                1.3           .0
sequence load elapsed time                                0.2           .0
hard parse (bind mismatch) elapsed time                   0.1           .0
failed parse elapsed time                                 0.0           .0
DB time                                             163,514.0          N/A
background elapsed time                               5,042.1          N/A
background cpu time                                      70.7          N/A
..
  Elapsed      CPU                  Elap per  % Total

  Time (s) Time (s) Executions Exec (s) DB Time SQL Id ---------- ---------- ------------ ---------- ------- -------------

   124,037 968 1 124036.5 75.9 4mmh51uun7bcx Module: mgrntw.exe
begin D_FORTIS.PRC_REMONTEE_PM_SUPPORT(:1 , :2 , :3 , :4 , :5 ,:FLD1 ,:FLD 2 ,:FLD3 ,:FLD4); end;

    14,195 221 438,448 0.0 8.7 aps7tsk52h9ac Module: mgrntw.exe
SELECT MVP.MVP_TAUX_SPECIFIQUE, M.MVT_ACTE_GESTION, M.MVT_SIGNE, D.DDC_EXERCICE,
 M.MVT_DATE_EFFET, M.MVT_N_ORIGINE, R.R_I_DATE_INVESTISSEMENT, GREATEST(D.DDC_DA
TE_INV + 1, R.R_I_DATE_INVESTISSEMENT), F_CONVERSION_DEVISE( D.DDC_PM_AU_TAUX_GA
RANTI + D.DDC_PARTICIPATION_BENEFICE + D.DDC_RETENUE, D.DDC_DEVISE, :B8 ), F_CON Thank you.

--
http://www.freelists.org/webpage/oracle-l

Received on Thu Sep 29 2011 - 02:39:48 CDT