| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
 |
 | |||
| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
|
| |||
Home -> Community -> Usenet -> c.d.o.server -> A myth of TKPROF output in Oracle 10.1.0.4
Hi
Could some one please shred me some light on the following TKPROF's
output.
My questions:
1) Why a user SQL statements are shown as part of the recursive call
section, in stead of the non-recursive call section.
2) Why some SQL statements did not have a "wait event" section. Eventhough a response times of that statement is very expensive.
3) Why a "FORALL" statement is too expensive.
++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
TKPROF: Release 10.1.0.4.0 - Production on Tue Feb 21 10:43:26 2006
Copyright (c) 1982, 2004, Oracle. All rights reserved.
Trace file: srpidhpr_ora_9518.trc
Sort options: default
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 ********************************************************************************
ALTER SESSION SET events '10046 trace name context forever, level 12'
call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0
0
Execute 1 0.00 0.00 0 0 0
0
Fetch 0 0.00 0.00 0 0 0
0
total 1 0.00 0.00 0 0 0
0
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 47 (IDH_APPLIC)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait TotalWaited
BEGIN DBMS_OUTPUT.GET_LINES(:LINES, :NUMLINES); END; call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 0 0
0
Execute 2 0.00 0.02 0 0 0
2
Fetch 0 0.00 0.00 0 0 0
0
total 4 0.00 0.02 0 0 0
2
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 47 (IDH_APPLIC)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait TotalWaited
BEGIN DBMS_OUTPUT.ENABLE(2000); END; call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0
0
Execute 1 0.00 0.00 0 0 0
1
Fetch 0 0.00 0.00 0 0 0
0
total 2 0.00 0.00 0 0 0
1
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 47 (IDH_APPLIC)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait TotalWaited
DECLARE
PROCEDURE WRITE_LOG(p_logMessage IN VARCHAR2
) as
BEGIN
BEGIN
dbms_output.PUT_LINE (p_logMessage);
EXCEPTION
WHEN OTHERS THEN
IF SQLCODE = -20000 THEN
dbms_output.DISABLE();
dbms_output.ENABLE(1000000);
dbms_output.PUT_LINE (p_logMessage);
END IF;
END;
f_update INTEGER; f_delete INTEGER;
WW_MASTER.TEMP_PROM_ITEM.CHG_ACTN_IND%TYPE; TYPE promotion_no_tab IS TABLE OF WW_MASTER.TEMP_PROM_ITEM.ST_PROM_NO%TYPE;TYPE group_code_tab IS TABLE OF
WW_MASTER.TEMP_PROM_ITEM.STD_SELL_PRC_AMT%TYPE; TYPE new_item_ind_tab IS TABLE OF NUMBER(1); dml_flag dml_flag_tab;
standard_sell_price standard_sell_price_tab; new_item_ind new_item_ind_tab; nat_prom_no promotion_no_tab;
b.st_prom_no, case when (SELECT MAX( TRUNC(SYSDATE) - PROM_START_DATE ) FROM WW_OPERATIONAL.PROM_HIST WHERE REF_NO = a.ref_no) > 70 then 0 else 1 end new_item_ind, a.std_sell_prc_amt, a.prom_sell_prc_amt, a.ref_no
a.chg_actn_ind = 'I';
CURSOR c_upd_cur
IS
select c.nat_prom_no, b.st_prom_no,
a.std_sell_prc_amt, a.prom_sell_prc_amt, a.ref_no
b.nat_prom_no = c.nat_prom_no and b.st_prom_no = d.st_prom_no and a.ref_no = d.ref_no and ( a.std_sell_prc_amt <> d.std_sell_prc_amt or a.prom_sell_prc_amt <> d.prom_sell_prc_amt) and a.chg_actn_ind = 'U';
a.ref_no
from temp_prom_item a, st_prom b
where a.st_prom_no = b.st_src_sys_id and
a.chg_actn_ind = 'D';
BEGIN
WRITE_LOG(' OPENED CURSOR FOR INSERTS AT '||TO_CHAR(SYSDATE,
'HH:MI:SS'));
OPEN c_ins_cur;
FETCH c_ins_cur BULK COLLECT INTO nat_prom_no, promotion_no,
new_item_ind, standard_sell_price,
promotional_sell_price, item_no;
CLOSE c_ins_cur;
WRITE_LOG(' FETCHED CURSOR FOR INSERTS AT '||TO_CHAR(SYSDATE,
'HH:MI:SS'));
WRITE_LOG(' START INSERTING INTO PROM_ITEM AT '||TO_CHAR(SYSDATE,
'HH:MI:SS'));
BEGIN
FORALL i IN 1 .. promotion_no.COUNT
INSERT INTO WW_OPERATIONAL.PROM_ITEM
( REF_NO, ST_PROM_NO, ASR_ITEM_IND, EDSD_ITEM_IND,
LOCK_STORE_UPDTE_IND, LOCK_EST_IND, NEW_ITEM_IND,
RVW_IND, EXCP_IND, PROM_SELL_PRC_AMT, STD_SELL_PRC_AMT)
VALUES
( item_no(i), promotion_no(i), 0, 0,
0, 0, new_item_ind(i),
0, 0, promotional_sell_price(i), standard_sell_price(i));
EXCEPTION
WHEN OTHERS THEN
WRITE_LOG('ERROR # 1: '||SQLCODE||SQLERRM);
RAISE_APPLICATION_ERROR( -20005, 'ERROR WHILE INSERTING INTO
PROM_ITEM. ');
END;
COMMIT;
BEGIN
FORALL i IN 1 .. promotion_no.COUNT
UPDATE WW_OPERATIONAL.ST_PROM
SET BUILD_QTY_CHG_FL = 1,
RVW_IND = 0,
EXCP_IND = CASE WHEN RVW_IND = 1 THEN 1 ELSE EXCP_IND END
WHERE ST_PROM_NO = promotion_no(i);
EXCEPTION
WHEN OTHERS THEN
WRITE_LOG('ERROR# 23: '||SQLCODE||SQLERRM);
RAISE_APPLICATION_ERROR( -20005, 'ERROR WHILE UPDATING
BUILD_QTY_CHG_FL. ');
END;
COMMIT;
BEGIN
FORALL i IN 1 .. promotion_no.COUNT
UPDATE WW_OPERATIONAL.PROM_ASRT
SET RVW_IND = 0,
EXCP_IND = CASE WHEN RVW_IND = 1 THEN 1 ELSE EXCP_IND END
WHERE ST_PROM_NO = promotion_no(i);
EXCEPTION
WHEN OTHERS THEN
WRITE_LOG('ERROR# 25: '||SQLCODE||SQLERRM);
RAISE_APPLICATION_ERROR( -20005, 'ERROR WHILE UPDATING PROM_ASRT
FOR EXCEPTION. ');
END;
COMMIT;
BEGIN
FORALL i IN 1 .. promotion_no.COUNT
UPDATE WW_OPERATIONAL.NAT_PROM
SET RVW_IND = 0,
EXCP_IND = CASE WHEN RVW_IND = 1 THEN 1 ELSE EXCP_IND END
WHERE NAT_PROM_NO = nat_prom_no(i);
EXCEPTION
WHEN OTHERS THEN
WRITE_LOG('ERROR# 27: '||SQLCODE||SQLERRM);
RAISE_APPLICATION_ERROR( -20005, 'ERROR WHILE UPDATING NAT_PROM FRO
EXCEPTION. ');
END;
COMMIT;
WRITE_LOG(' START INITIALIZING COLLECTION AT '||TO_CHAR(SYSDATE,
'HH:MI:SS'));
FOR i IN 1 .. promotion_no.COUNT
LOOP
promotion_no(i) := null;
item_no(i) := null;
promotional_sell_price(i) := null;
standard_sell_price(i) := null;
new_item_ind(i) := null;
nat_prom_no(i) := null;
END LOOP;
WRITE_LOG(' END INITIALIZING COLLECTION AT '||TO_CHAR(SYSDATE,
'HH:MI:SS'));
WRITE_LOG(' END INSERTING INTO PROM_ITEM AT '||TO_CHAR(SYSDATE,
'HH:MI:SS'));
BEGIN
SELECT 1
INTO f_update
FROM DUAL
WHERE EXISTS
( SELECT 1
FROM WW_MASTER.TEMP_PROM_ITEM
WHERE CHG_ACTN_IND = 'U');
EXCEPTION
WHEN NO_DATA_FOUND THEN
f_update := 0;
END;
IF f_update = 1
THEN
WRITE_LOG(' START FETCHING FOR UPDATES AT '||TO_CHAR(SYSDATE,
'HH:MI:SS'));
OPEN c_upd_cur;
FETCH c_upd_cur BULK COLLECT INTO nat_prom_no, promotion_no,
standard_sell_price,
promotional_sell_price,
item_no;
WRITE_LOG(' END FETCHING FOR UPDATES AT '||TO_CHAR(SYSDATE,
'HH:MI:SS'));
CLOSE c_upd_cur;
WRITE_LOG(' START UPDATING NAT_PROM WITH EXCEPTIONS AT
'||TO_CHAR(SYSDATE, 'HH:MI:SS'));
BEGIN
FORALL i IN 1 .. nat_prom_no.COUNT
UPDATE WW_OPERATIONAL.NAT_PROM
SET EXCP_IND = 1,
RVW_IND = 0,
LOCK_IND = 0
WHERE NAT_PROM_NO = nat_prom_no(i);
EXCEPTION
WHEN OTHERS THEN
ROLLBACK;
WRITE_LOG('ERROR # 2'||SQLCODE||SQLERRM);
RAISE_APPLICATION_ERROR( -20005, 'ERROR WHILE UPDATING NAT_PROM.');
END;
WRITE_LOG(' END UPDATING NAT_PROM WITH EXCEPTIONS AT
'||TO_CHAR(SYSDATE, 'HH:MI:SS'));
WRITE_LOG(' START UPDATING ST_PROM WITH EXCEPTIONS AT
'||TO_CHAR(SYSDATE, 'HH:MI:SS'));
BEGIN
FORALL i IN 1 .. nat_prom_no.COUNT
UPDATE WW_OPERATIONAL.ST_PROM
SET EXCP_IND = 1,
RVW_IND = 0
WHERE ST_PROM_NO = promotion_no(i);
EXCEPTION
WHEN OTHERS THEN
ROLLBACK;
WRITE_LOG('ERROR # 2'||SQLCODE||SQLERRM);
RAISE_APPLICATION_ERROR( -20005, 'ERROR WHILE UPDATING ST_PROM.');
END;
WRITE_LOG(' END UPDATING ST_PROM WITH EXCEPTIONS AT
'||TO_CHAR(SYSDATE, 'HH:MI:SS'));
WRITE_LOG(' START UPDATING PROM_ITEM WITH EXCEPTIONS AT
'||TO_CHAR(SYSDATE, 'HH:MI:SS'));
BEGIN
FORALL i IN 1 .. nat_prom_no.COUNT
UPDATE WW_OPERATIONAL.PROM_ITEM
SET EXCP_IND = 1,
RVW_IND = 0,
PROM_SELL_PRC_AMT = promotional_sell_price(i),
STD_SELL_PRC_AMT = standard_sell_price(i)
WHERE ST_PROM_NO = promotion_no(i) AND
REF_NO = item_no(i) ;
EXCEPTION
WHEN OTHERS THEN
ROLLBACK;
WRITE_LOG('ERROR # 2'||SQLCODE||SQLERRM);
RAISE_APPLICATION_ERROR( -20005, 'ERROR WHILE UPDATING
PROM_ITEM.');
END;
COMMIT;
WRITE_LOG(' END UPDATING PROM_ITEM WITH EXCEPTIONS AT
'||TO_CHAR(SYSDATE, 'HH:MI:SS'));
END IF;
WRITE_LOG(' START INITIALIZING COLLECTION FOR DELETES AT
'||TO_CHAR(SYSDATE, 'HH:MI:SS'));
FOR i IN 1 .. promotion_no.COUNT
LOOP
promotion_no(i) := null;
item_no(i) := null;
END LOOP;
WRITE_LOG(' END INITIALIZING COLLECTION FOR DELETES AT
'||TO_CHAR(SYSDATE, 'HH:MI:SS'));
BEGIN
SELECT 1
INTO f_delete
FROM DUAL
WHERE EXISTS
( SELECT 1
FROM WW_MASTER.TEMP_PROM_ITEM
WHERE CHG_ACTN_IND = 'D');
EXCEPTION
WHEN NO_DATA_FOUND THEN
f_delete := 0;
END;
IF f_delete = 1
THEN
WRITE_LOG(' START FETCHING FOR DELETES AT '||TO_CHAR(SYSDATE,
'HH:MI:SS'));
OPEN c_del_cur;
FETCH c_del_cur BULK COLLECT INTO promotion_no, item_no;
WRITE_LOG(' END FETCHING FOR DELETES AT '||TO_CHAR(SYSDATE,
'HH:MI:SS'));
WRITE_LOG(' START DELETING AT '||TO_CHAR(SYSDATE, 'HH:MI:SS'));
BEGIN
FORALL i IN 1 .. promotion_no.COUNT
DELETE FROM PROM_WKY_EST
WHERE ST_PROM_NO = promotion_no(i) AND
REF_NO = item_no(i);
EXCEPTION
WHEN OTHERS THEN
ROLLBACK;
WRITE_LOG(' ERROR # 5 '||SQLCODE||SQLERRM);
RAISE_APPLICATION_ERROR( -20005, 'ERROR WHILE DELETING FROM
PROM_WKY_EST.');
END;
BEGIN
FORALL i IN 1 .. promotion_no.COUNT
DELETE FROM PROM_DLY_EST
WHERE ST_PROM_NO = promotion_no(i) AND
REF_NO = item_no(i);
EXCEPTION
WHEN OTHERS THEN
ROLLBACK;
WRITE_LOG(' ERROR # 6 '||SQLCODE||SQLERRM);
RAISE_APPLICATION_ERROR( -20005, 'ERROR WHILE DELETING FROM
PROM_DLY_EST.');
END;
BEGIN
FORALL i IN 1 .. promotion_no.COUNT
DELETE FROM PROM_ITEM
WHERE REF_NO = item_no(i) AND
ST_PROM_NO = promotion_no(i);
EXCEPTION
WHEN OTHERS THEN
ROLLBACK;
WRITE_LOG(' ERROR # 7 '||SQLCODE||SQLERRM);
RAISE_APPLICATION_ERROR( -20005, 'ERROR WHILE DELETING FROM
PROM_ITEM.');
END;
COMMIT;
WRITE_LOG('END DELETING AT '||TO_CHAR(SYSDATE, 'HH:MI:SS'));
END IF;
WRITE_LOG(' START TIME : '||TO_CHAR(SYSDATE, 'HH:MI:SS'));
LOAD_PROMO_ITEM;
WRITE_LOG(' END TIME : '||TO_CHAR(SYSDATE, 'HH:MI:SS'));
END;
call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 1 0.10 0.09 0 0 0
0
Execute 1 2.31 2.33 0 0 4
1
Fetch 0 0.00 0.00 0 0 0
0
total 2 2.41 2.42 0 0 4
1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 47 (IDH_APPLIC)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait TotalWaited
SELECT B.NAT_PROM_NO, B.ST_PROM_NO, CASE WHEN (SELECT MAX(
TRUNC(SYSDATE) -
PROM_START_DATE )
FROM
WW_OPERATIONAL.PROM_HIST WHERE REF_NO = A.REF_NO) > 70 THEN 0 ELSE 1
END
NEW_ITEM_IND, A.STD_SELL_PRC_AMT, A.PROM_SELL_PRC_AMT, A.REF_NO FROM
TEMP_PROM_ITEM A, ST_PROM B WHERE A.ST_PROM_NO = B.ST_SRC_SYS_ID AND
A.CHG_ACTN_IND = 'I'
call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0
0
Execute 1 0.00 0.00 0 0 0
0
Fetch 1 769.48 1268.40 374933 84936470 0
327394
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 47 (IDH_APPLIC) (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------327394 HASH JOIN (cr=13409 pr=0 pw=0 time=1722449 us) 188750 PARTITION RANGE ALL PARTITION: 1 6 (cr=8186 pr=0 pw=0 time=377596 us)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT MODE: ALL_ROWS
0 SORT (AGGREGATE)
0 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF
'PROM_HIST'
(TABLE)
0 INDEX MODE: ANALYZED (RANGE SCAN) OF 'IK16_PROM_HIST'
(INDEX)
188750 TABLE ACCESS MODE: ANALYZED (FULL) OF 'ST_PROM' (TABLE)
PARTITION: START=1 STOP=6
327394 TABLE ACCESS MODE: ANALYZED (FULL) OF 'TEMP_PROM_ITEM'
(TABLE)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total
Waited
INSERT INTO WW_OPERATIONAL.PROM_ITEM ( REF_NO, ST_PROM_NO,
ASR_ITEM_IND,
EDSD_ITEM_IND, LOCK_STORE_UPDTE_IND, LOCK_EST_IND, NEW_ITEM_IND,
RVW_IND,
EXCP_IND, PROM_SELL_PRC_AMT, STD_SELL_PRC_AMT)
VALUES
( :B1 , :B2 , 0, 0, 0, 0, :B3 , 0, 0, :B4 , :B5 )
call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0
0
Execute 1 20.91 26.08 789 27219 3214733
327394
Fetch 0 0.00 0.00 0 0 0
0
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 47 (IDH_APPLIC) (recursive depth: 1)
Rows Execution Plan
------- ---------------------------------------------------
0 INSERT STATEMENT MODE: ALL_ROWS
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total
Waited
select file#
from
file$ where ts#=:1
call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 129 0.01 0.02 0 0 0
0
Execute 129 0.13 0.71 0 0 0
0
Fetch 930 0.01 0.01 0 1731 0
801
total 1188 0.15 0.75 0 1731 0
801
Misses in library cache during parse: 0
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Rows Row Source Operation
------- ---------------------------------------------------
8 TABLE ACCESS BY INDEX ROWID FILE$ (cr=17 pr=0 pw=0 time=150
us)
8 INDEX RANGE SCAN I_FILE2 (cr=9 pr=0 pw=0 time=157 us)(object
id 42)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait TotalWaited
update tsq$ set
blocks=:3,maxblocks=:4,grantor#=:5,priv1=:6,priv2=:7,priv3=:8
where
ts#=:1 and user#=:2
call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 15 0.00 0.00 0 0 0
0
Execute 15 0.07 0.52 0 52 15
15
Fetch 0 0.00 0.00 0 0 0
0
total 30 0.07 0.52 0 52 15
15
Misses in library cache during parse: 0
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Rows Row Source Operation
------- ---------------------------------------------------
0 UPDATE (cr=4 pr=0 pw=0 time=512 us)
1 TABLE ACCESS CLUSTER TSQ$ (cr=4 pr=0 pw=0 time=233 us)
1 INDEX UNIQUE SCAN I_USER# (cr=1 pr=0 pw=0 time=33 us)(object
id 11)
update seg$ set
type#=:4,blocks=:5,extents=:6,minexts=:7,maxexts=:8,extsize=
:9,extpct=:10,user#=:11,iniexts=:12,lists=decode(:13, 65535, NULL,
:13),
groups=decode(:14, 65535, NULL, :14), cachehint=:15, hwmincr=:16,
spare1=
DECODE(:17,0,NULL,:17),scanhint=:18
where
ts#=:1 and file#=:2 and block#=:3
call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 15 0.00 0.00 0 0 0
0
Execute 15 0.26 1.19 0 75 15
15
Fetch 0 0.00 0.00 0 0 0
0
total 30 0.26 1.19 0 75 15
15
Misses in library cache during parse: 0
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Rows Row Source Operation
------- ---------------------------------------------------
0 UPDATE (cr=5 pr=0 pw=0 time=312 us)
1 TABLE ACCESS CLUSTER SEG$ (cr=5 pr=0 pw=0 time=151 us)
1 INDEX UNIQUE SCAN I_FILE#_BLOCK# (cr=2 pr=0 pw=0 time=28
us)(object id 9)
UPDATE WW_OPERATIONAL.ST_PROM SET BUILD_QTY_CHG_FL = 1, RVW_IND = 0, EXCP_IND
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0
0
Execute 1 360.19 1799.29 0 982245 677629
327394
Fetch 0 0.00 0.00 0 0 0
0
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 47 (IDH_APPLIC) (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------327394 UPDATE (cr=983038 pr=0 pw=0 time=27932704 us) 327394 TABLE ACCESS BY GLOBAL INDEX ROWID ST_PROM PARTITION: ROW LOCATION ROW LOCATION (cr=982184 pr=0 pw=0 time=5239186 us) 327394 INDEX UNIQUE SCAN PK_ST_PROM (cr=654790 pr=0 pw=0 time=2540913 us)(object id 69189)
Rows Execution Plan
------- ---------------------------------------------------
0 UPDATE STATEMENT MODE: ALL_ROWS
327394 UPDATE OF 'ST_PROM'
'ST_PROM' (TABLE) PARTITION:ROW LOCATION
327394 INDEX MODE: ANALYZED (UNIQUE SCAN) OF 'PK_ST_PROM' (INDEX
(UNIQUE))
********************************************************************************
UPDATE WW_OPERATIONAL.PROM_ASRT SET RVW_IND = 0, EXCP_IND = CASE WHEN RVW_IND
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0
0
Execute 1 398.22 2082.41 180 845142 388273
190214
Fetch 0 0.00 0.00 0 0 0
0
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 47 (IDH_APPLIC) (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------190214 UPDATE (cr=845142 pr=180 pw=0 time=34106085 us) 190214 TABLE ACCESS BY INDEX ROWID PROM_ASRT (cr=845002 pr=180 pw=0 time=12131193 us)
Rows Execution Plan
------- ---------------------------------------------------
0 UPDATE STATEMENT MODE: ALL_ROWS
190214 UPDATE OF 'PROM_ASRT'
(TABLE)
190214 INDEX MODE: ANALYZED (UNIQUE SCAN) OF 'PK_PROM_ASRT'
(INDEX (UNIQUE))
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total
Waited
UPDATE WW_OPERATIONAL.NAT_PROM SET RVW_IND = 0, EXCP_IND = CASE WHEN
RVW_IND =
1 THEN 1 ELSE EXCP_IND END
WHERE
NAT_PROM_NO = :B1
call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0
0
Execute 1 401.08 2086.53 2533 327452 336060
327394
Fetch 0 0.00 0.00 0 0 0
0
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 47 (IDH_APPLIC) (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------327394 UPDATE (cr=327452 pr=2533 pw=0 time=39210456 us) 327394 INDEX UNIQUE SCAN PK_NAT_PROM (cr=327396 pr=28 pw=0 time=4660668 us)(object id 70804)
Rows Execution Plan
------- ---------------------------------------------------
0 UPDATE STATEMENT MODE: ALL_ROWS
327394 UPDATE OF 'NAT_PROM'
Event waited on Times Max. Wait TotalWaited
SELECT 1
FROM
DUAL WHERE EXISTS ( SELECT 1 FROM WW_MASTER.TEMP_PROM_ITEM WHERE
CHG_ACTN_IND = 'U')
call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0
0
Execute 1 0.74 6.98 5221 5223 0
0
Fetch 1 0.00 0.00 0 0 0
0
total 3 0.74 6.99 5221 5223 0
0
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 47 (IDH_APPLIC) (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
0 FILTER (cr=5223 pr=5221 pw=0 time=6986204 us)
0 FAST DUAL (cr=0 pr=0 pw=0 time=0 us)
0 TABLE ACCESS FULL TEMP_PROM_ITEM (cr=5223 pr=5221 pw=0
time=6986186 us)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT MODE: ALL_ROWS
0 FILTER
0 FAST DUAL
0 TABLE ACCESS MODE: ANALYZED (FULL) OF 'TEMP_PROM_ITEM'
(TABLE)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total
Waited
SELECT 1
FROM
DUAL WHERE EXISTS ( SELECT 1 FROM WW_MASTER.TEMP_PROM_ITEM WHERE
CHG_ACTN_IND = 'D')
call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.00 0 0 0
0
Execute 1 0.11 0.11 0 5223 0
0
Fetch 1 0.00 0.00 0 0 0
0
total 3 0.12 0.11 0 5223 0
0
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 47 (IDH_APPLIC) (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
0 FILTER (cr=5223 pr=0 pw=0 time=113807 us)
0 FAST DUAL (cr=0 pr=0 pw=0 time=0 us)
0 TABLE ACCESS FULL TEMP_PROM_ITEM (cr=5223 pr=0 pw=0
time=113787 us)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT MODE: ALL_ROWS
0 FILTER
0 FAST DUAL
0 TABLE ACCESS MODE: ANALYZED (FULL) OF 'TEMP_PROM_ITEM'
(TABLE)
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 4 0.10 0.09 0 0 0
0
Execute 5 2.31 2.36 0 0 4
4
Fetch 0 0.00 0.00 0 0 0
0
total 9 2.41 2.45 0 0 4
4
Misses in library cache during parse: 1
Elapsed times include waiting on following events:
Event waited on Times Max. Wait TotalWaited
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS call count cpu elapsed disk query current
rows
------- ------ -------- ---------- ---------- ---------- ----------
Parse 166 0.02 0.04 0 0 0
0
Execute 166 1181.71 6003.85 8723 2192631 4616725
1172426
Fetch 933 769.49 1268.42 374933 84938201 0
328195
Misses in library cache during parse: 7
Misses in library cache during execute: 4
Elapsed times include waiting on following events:
Event waited on Times Max. Wait TotalWaited
12 user SQL statements in session.
159 internal SQL statements in session.
171 SQL statements in session.
7 statements EXPLAINed in this session.
1 session in tracefile.
12 user SQL statements in trace file.
159 internal SQL statements in trace file.
171 SQL statements in trace file.
14 unique SQL statements in trace file.
7 SQL statements EXPLAINed using schema:
orametrics.plan_table
Schema was specified.
Existing table was used.
7275 elapsed seconds in trace file. Received on Sun Feb 26 2006 - 17:38:04 CST
 |
 |