Profiling example
Each phase in the SQL query processing that exceeds the profiling value is printed. The following is a sample ORAPROF file:
98-03-09[15:00:39]: Profiling value = 0.02 sec
------ Profiling value exceeded -----
<jim><bshellmain>:98-03-09[15:01:16.054]: Time (multi_fetch) : 0.033598 seconds
SQL statement:
SELECT /*+ FIRST_ROWS USE_NL(a,b,c) INDEX(a tttadv112000$idx1) */ a.t$pacc,a.t$
cpac,a.t$sequ,b.t$desc,c.t$expi FROM baan5.tttadv112000 a,baan5.tttadv130000 b,
baan5.tttadv200000 c WHERE c.t$cpac = :1 AND c.t$cmod = :2 AND c.t$cses = :3
AND c.t$vers = a.t$vers AND c.t$rele = a.t$rele AND c.t$cust = a.t$cust AND b.t
$cpac = :4 AND b.t$vers = a.t$vers AND b.t$rele = a.t$rele AND b.t$cust = a.t$
cust AND b.t$kdes = :5 AND b.t$rkey = :6 AND b.t$clan = :7 AND a.t$pacc = :8
AND a.t$cpac = :9 ORDER BY 1,2,3
-------------------------------------
------ Profiling value exceeded -----
<jim><bshellmain>:98-03-09[15:01:16.101]:
Time (parse) : 0.023754 seconds
SQL statement:
SELECT /*+ FIRST_ROWS INDEX(a tdctcs440000$idx9) */ a.t$adat,a.t$bfix,a.t$ccod,
a.t$cdat,a.t$cgrp,a.t$conf,a.t$cprj,a.t$csta,a.t$ctyp,a.t$delc,a.t$dsca,a.t$dti
m,a.t$ercs,a.t$erss,a.t$etim,a.t$fdat,a.t$fre1,a.t$fre2,a.t$fre3,a.t$fre4,a.t$f
re5,a.t$fre6,a.t$fre7,a.t$ider,a.t$idln,a.t$loca,a.t$modc,a.t$name,a.t$pact,a.t
$phse,a.t$pref,a.t$prgr,a.t$prib,a.t$prio,a.t$prjm,a.t$rdat,a.t$rtim,a.t$rtst,a
.t$rtyp,a.t$rusr,a.t$sact,a.t$scmp,a.t$sdat,a.t$solv,a.t$stat,a.t$ttim,a.t$txta,
a.t$txtp,a.t$txts,a.t$unit,a.t$uref,a.t$utyp,a.t$vref FROM baan5.tdctcs440000 a
WHERE a.t$delc = :1 AND (a.t$loca >= :2) AND (a.t$loca <= :3) AND (a.t$rtyp =
:4 AND a.t$unit = :5 AND a.t$uref = :6 AND a.t$utyp = :7 AND a.t$scmp = :8
AND a.t$vref = :9 AND a.t$csta = :10 AND a.t$loca > :11)
ORDER BY 39,50,51,52,42,53,8,26,24
-------------------------------------
The example shows two queries; the first has an execution time that exceeds the limit, while the second has a parse time that exceeds the limit.