I have a trace (attached) for a procedure that is taking much longer than what is expected on a clients server. It performs well on our development servers and on other clients databases that have much more data. All of the queries executed by the procedure are performing as expected.
DECLARE v_return NUMBER := 0; BEGIN P_CHARTS.newEdition( :1_cv_id )
; END;
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 2256.04 2257.69 0 63 72826 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 2256.04 2257.69 0 63 72826 1
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 109
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 1 0.00 0.00
log file sync 1 0.00 0.00
SQL*Net message from client 1 0.00 0.00
********************************************************************************
However all the sql executed by this package seems to be performing as expected.
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 41015 0.84 0.86 0 192 30 0
Execute 1242445 69.40 71.98 1469 111890 2983402 451311
Fetch 1243552 17.92 18.37 362 1654934 329 738338
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2527012 88.17 91.22 1831 1767016 2983761 1189649
Here are the waits in the statpack report (attached)...
Time Model System Stats DB/Inst: PROD/prod Snaps: 1949-1950
-> Ordered by % of DB time desc, Statistic name
Statistic Time (s) % DB time
----------------------------------- -------------------- ---------
sql execute elapsed time 2,013.4 99.8
DB CPU 1,998.8 99.1
PL/SQL execution elapsed time 1,918.2 95.1
parse time elapsed 6.1 .3
hard parse elapsed time 5.5 .3
connection management call elapsed 1.3 .1
hard parse (sharing criteria) elaps 0.6 .0
PL/SQL compilation elapsed time 0.3 .0
repeated bind elapsed time 0.1 .0
sequence load elapsed time 0.1 .0
failed parse elapsed time 0.0 .0
hard parse (bind mismatch) elapsed 0.0 .0
DB time 2,016.8
background elapsed time 234.9
background cpu time 0.9
-------------------------------------------------------------
Foreground Wait Events DB/Inst: PROD/prod Snaps: 1949-1950
-> Only events with Total Wait Time (s) >= .001 are shown
-> ordered by Total Wait Time desc, Waits desc (idle events last)
Avg %Total
%Tim Total Wait wait Waits Call
Event Waits out Time (s) (ms) /txn Time
---------------------------- ------------ ---- ---------- ------ -------- ------
db file sequential read 5,941 0 8 1 15.4 .0
db file scattered read 6,489 0 8 1 16.9 .0
Failed Logon Delay 1 100 1 1002 0.0 .0
control file sequential read 1,092 0 0 0 2.8 .0
Disk file operations I/O 216 0 0 1 0.6 .0
log file sync 52 0 0 2 0.1 .0
db file parallel read 17 0 0 4 0.0 .0
log file switch completion 1 0 0 31 0.0 .0
direct path write temp 5 0 0 5 0.0 .0
row cache lock 2 0 0 8 0.0 .0
SQL*Net message from client 775 0 15,952 20584 2.0
jobq slave wait 3,711 94 1,832 494 9.6
SQL*Net message to client 772 0 0 0 2.0
What could explain the discrepancy between the times of the non recursive and recursive SQL?
Thanks in advance