Hi,
i got a piece of code from our developer to change it into a fast forall insert.
But my change ended in a slower way to do the same work.
It comes down to the fact, that my insert into is a lot slower than the insert into in the original code.
I did not get it.
here is the original code, shortend.
Some logic is missing, but it comes down to about 40.000 inserts .
FOR c IN (SELECT nvl(bstd_anfbst, 0) + nvl(bstd_plus, 0) - nvl(bstd_asou, 0) -
nvl(bstd_asmu, 0) AS l_bsdoc_anfbst,
bsd_at_at_se_se_ag_ag_wg AS l_bstd_ber,
bsd_at_at_se_se_ag_ag_no AS l_bstd_wgr,
bsd_at_at_se_se_no AS l_bstd_agr,
bsd_at_at_no AS l_bstd_anr,
bstd_gek AS l_bstd_gek
FROM bsd
WHERE bstd_zen = p_filiale
ORDER BY bsd_at_at_se_se_ag_ag_wg ASC,
bsd_at_at_se_se_ag_ag_no ASC,
bsd_at_at_se_se_no ASC,
bsd_at_at_no ASC)
LOOP
IF c.l_bsdoc_anfbst != 0 THEN
l_stat := doku_bsdoc_create(p_filiale,
p_jahr,
p_monat,
c.l_bstd_ber,
c.l_bstd_wgr,
c.l_bstd_agr,
c.l_bstd_anr,
c.l_bsdoc_anfbst,
c.l_bstd_gek);
END LOOP;
FUNCTION doku_bsdoc_create(p_filiale IN NUMBER,
p_jahr IN NUMBER,
p_monat IN NUMBER,
p_bereich IN NUMBER,
p_warengrp IN NUMBER,
p_artikelgrp IN NUMBER,
p_artikelnr IN NUMBER,
p_anfang_bestand IN NUMBER,
p_gleitek IN NUMBER) RETURN NUMBER
WHILE l_anzahl = 0 AND l_zz_vmon >= 0
LOOP
BEGIN
l_periode := get_bsdoc_periode(l_jahr, l_monat);
l_meldung := 'INSERT bs';
INSERT INTO bs_loop
(bs_at_at_se_se_ag_ag_wg,
bs_at_at_se_se_ag_ag_no,
bs_at_at_se_se_no,
bs_at_at_no,
bsdoc_jahr,
bsdoc_mon,
bsdoc_zen,
bsdoc_anfbst,
bsdoc_plus,
bsdoc_asmu,
bsdoc_asou,
bsdoc_ekums,
bsdoc_vkums,
bsdoc_invek,
bsdoc_diff,
bsdoc_user,
bsdoc_aend,
bsdoc_periode,
bsdoc_gek)
VALUES
(p_bereich,
p_warengrp,
p_artikelgrp,
p_artikelnr,
l_jahr,
l_monat,
p_filiale,
p_anfang_bestand,
0,
0,
0,
0,
0,
p_gleitek,
p_gleitek,
g_user_z,
g_heute,
l_periode,
p_gleitek);
EXCEPTION
WHEN dup_val_on_index THEN
l_stat := 0;
l_anzahl := 1; -- Satz ist vorhanden
END;
END doku_bsdoc_create;
Now my code with bulk collect and forall
procedure new_doku_create (
p_filiale in number,
p_jahr in number,
p_monat in number,
p_update in varchar2 default null,
o_change out varchar2 )
is
cursor c_ins_bs (
t_user in number,
t_heute in date,
t_filiale in number
) is
SELECT bsd_at_at_se_se_ag_ag_wg AS l_bstd_ber,
bsd_at_at_se_se_ag_ag_no AS l_bstd_wgr,
bsd_at_at_se_se_no AS l_bstd_agr,
bsd_at_at_no as l_bstd_anr,
bstd_zen,
nvl(bstd_anfbst, 0) + nvl(bstd_plus, 0) - nvl(bstd_asou, 0) - nvl(bstd_asmu, 0) AS l_bsdoc_anfbst,
0 bsdoc_plus,
0 bsdoc_asmu,
0 bsdoc_asou,
0 bsdoc_ekums,
0 bsdoc_vkums,
' ' bsdoc_abcu,
' ' bsdoc_abce,
'' bsdoc_abcd,
t_user,
trunc(sysdate) t_heute,
0 bsdoc_invmg,
bstd_gek as l_bsdoc_invek,
'' bsdoc_invd,
bstd_gek as l_bsdoc_diff,
--get_bsdoc_periode(t_jahr, t_monat) as l_periode,
0 vid,
bstd_gek as l_bsdoc_gek
FROM bsd
WHERE bstd_zen = t_filiale
and nvl(bstd_anfbst, 0) + nvl(bstd_plus, 0) - nvl(bstd_asou, 0) - nvl(bstd_asmu, 0) != 0
;
t_bs_at_at_se_se_ag_ag_wg dbms_sql.number_table;
t_bs_at_at_se_se_ag_ag_no dbms_sql.number_table;
t_bs_at_at_se_se_no dbms_sql.number_table;
t_bs_at_at_no dbms_sql.number_table;
t_bsdoc_jahr dbms_sql.number_table;
t_bsdoc_mon dbms_sql.number_table;
t_bsdoc_zen dbms_sql.number_table;
t_bsdoc_anfbst dbms_sql.number_table;
t_bsdoc_plus dbms_sql.number_table;
t_bsdoc_asmu dbms_sql.number_table;
t_bsdoc_asou dbms_sql.number_table;
t_bsdoc_ekums dbms_sql.number_table;
t_bsdoc_vkums dbms_sql.number_table;
t_bsdoc_abcu dbms_sql.varchar2_table;
t_bsdoc_abce dbms_sql.varchar2_table;
t_bsdoc_abcd dbms_sql.date_table;
t_bsdoc_user dbms_sql.number_table;
t_bsdoc_aend dbms_sql.date_table;
t_bsdoc_invmg dbms_sql.number_table;
t_bsdoc_invek dbms_sql.number_table;
t_bsdoc_invd dbms_sql.date_table;
t_bsdoc_diff dbms_sql.number_table;
t_bsdoc_periode dbms_sql.number_table;
t_vid dbms_sql.number_table;
t_bsdoc_gek dbms_sql.number_table;
jahr number;
monat number;
periode number;
bulk_errors exception;
pragma exception_init( bulk_errors, -24381); --bulk exception for forall
v_datum date;
v_monate number;
l_monat number;
l_jahr number;
v_dummy date;
o_update number default 0;
begin
--begin
v_dummy := add_months(v_datum, - v_monate);
l_monat := to_char(v_dummy,'mm');
l_jahr := to_char(v_dummy,'yyyy');
open c_ins_bs (g_user_z, g_heute, p_filiale);
loop
fetch c_ins_bs bulk collect
into t_bs_at_at_se_se_ag_ag_wg,
t_bs_at_at_se_se_ag_ag_no,
t_bs_at_at_se_se_no,
t_bs_at_at_no,
t_bsdoc_zen,
t_bsdoc_anfbst,
t_bsdoc_plus,
t_bsdoc_asmu,
t_bsdoc_asou,
t_bsdoc_ekums,
t_bsdoc_vkums,
t_bsdoc_abcu,
t_bsdoc_abce,
t_bsdoc_abcd,
t_bsdoc_user,
t_bsdoc_aend,
t_bsdoc_invmg,
t_bsdoc_invek,
t_bsdoc_invd,
t_bsdoc_diff,
t_vid,
t_bsdoc_gek
limit 1000;
exit when t_vid.count = 0;
v_datum := to_date('01' || to_char(p_monat, '09') || p_jahr, 'DDMMYYYY');
v_monate := 0;
while v_monate <= g_budb_vor_tgab_z
loop
begin
monat := p_monat - v_monate;
jahr := p_jahr;
periode := get_bsdoc_periode(p_jahr, p_monat);
forall bs_index in t_vid.first .. t_vid.last
save exceptions
insert into bs_bulk
(
bs_at_at_se_se_ag_ag_wg,
bs_at_at_se_se_ag_ag_no,
bs_at_at_se_se_no,
bs_at_at_no,
bsdoc_jahr,
bsdoc_mon,
bsdoc_zen,
bsdoc_anfbst,
bsdoc_plus,
bsdoc_asmu,
bsdoc_asou,
bsdoc_ekums,
bsdoc_vkums,
bsdoc_abcu,
bsdoc_abce,
bsdoc_abcd,
bsdoc_user,
bsdoc_aend,
bsdoc_invmg,
bsdoc_invek,
bsdoc_invd,
bsdoc_diff,
bsdoc_periode,
vid,
bsdoc_gek
)
values
(
t_bs_at_at_se_se_ag_ag_wg(bs_index),
t_bs_at_at_se_se_ag_ag_no(bs_index),
t_bs_at_at_se_se_no(bs_index),
t_bs_at_at_no(bs_index),
jahr,
monat,
t_bsdoc_zen(bs_index),
t_bsdoc_anfbst(bs_index),
t_bsdoc_plus(bs_index),
t_bsdoc_asmu(bs_index),
t_bsdoc_asou(bs_index),
t_bsdoc_ekums(bs_index),
t_bsdoc_vkums(bs_index),
t_bsdoc_abcu(bs_index),
t_bsdoc_abce(bs_index),
t_bsdoc_abcd(bs_index),
t_bsdoc_user(bs_index),
t_bsdoc_aend(bs_index),
t_bsdoc_invmg(bs_index),
t_bsdoc_invek(bs_index),
t_bsdoc_invd(bs_index),
t_bsdoc_diff(bs_index),
periode,
t_vid(bs_index),
t_bsdoc_gek(bs_index)
);
--o_change := to_char(t_ins_bs.count);
v_monate := v_monate + 1;
exception
when bulk_errors
then
v_monate := v_monate +1;
end;
end loop;
end loop;
close c_ins_bs;
end new_doku_create;
It will also insert about 40.000 rows.
But tested with runstats_pkg it shows:
Run1 is the normal loop.
Run2 is the forall.
================================================================================
Runstats report : 04-SEP-2010 11:57:36
================================================================================
--------------------------------------------------------------------------------
1. Summary timings
--------------------------------------------------------------------------------
Run1 ran in 3051 hsecs
Run2 ran in 6823 hsecs
Run1 was 55,3% quicker than Run2
--------------------------------------------------------------------------------
2. Statistics report
--------------------------------------------------------------------------------
Type Name Run1 Run2 Diff
----- ----------------------------------- ------------ ------------ ------------
STAT redo log space wait time 39 1,160 1,121
LATCH object queue header heap 177 1,332 1,155
LATCH shared pool 499 1,745 1,246
LATCH multiblock read objects 64,334 65,684 1,350
STAT write clones created in foreground 88 1,620 1,532
STAT calls to kcmgas 98 1,663 1,565
STAT physical reads cache prefetch 475,673 474,059 -1,614
STAT commit txn count during cleanout 302 2,077 1,775
STAT table scan rows gotten 21,215,060 21,216,912 1,852
LATCH redo writing 331 2,869 2,538
STAT CPU used when call started 2,984 5,605 2,621
STAT CPU used by this session 2,980 5,605 2,625
STAT dirty buffers inspected 1,995 4,678 2,683
STAT recursive cpu usage 2,884 5,601 2,717
LATCH messages 903 4,287 3,384
STAT DB time 3,055 6,823 3,768
STAT physical reads 508,190 512,858 4,668
STAT physical reads cache 508,190 512,858 4,668
STAT physical read IO requests 32,517 38,799 6,282
STAT physical read total IO requests 32,517 38,799 6,282
LATCH In memory undo latch 40,354 32,112 -8,242
STAT index scans kdiixs1 17,282 32,039 14,757
STAT rows fetched via callback 17,266 32,043 14,777
STAT cluster key scan block gets 17,261 32,039 14,778
STAT cluster key scans 17,261 32,039 14,778
STAT opened cursors cumulative 17,276 32,082 14,806
STAT session cursor cache hits 17,265 32,075 14,810
STAT parse count (total) 17,276 32,130 14,854
STAT free buffer requested 510,391 525,418 15,027
STAT free buffer inspected 510,475 526,135 15,660
LATCH enqueues 18,138 1,448 -16,690
LATCH library cache 17,839 661 -17,178
LATCH session idle bit 17,307 109 -17,198
LATCH simulator lru latch 5,438 31,150 25,712
LATCH undo global data 6,294 32,503 26,209
STAT table fetch by rowid 34,528 64,081 29,553
STAT index fetch by key 34,527 64,082 29,555
LATCH checkpoint queue latch 6,238 35,814 29,576
STAT active txn count during cleanout 94 30,151 30,057
STAT calls to kcmgcs 701 31,046 30,345
STAT cleanout - number of ktugct calls 393 31,992 31,599
LATCH session allocation 34,974 709 -34,265
STAT execute count 68,098 32,181 -35,917
STAT recursive calls 217,550 257,602 40,052
STAT no work - consistent read gets 559,743 604,133 44,390
STAT calls to get snapshot scn: kcmgss 17,557 63,527 45,970
LATCH cache buffers lru chain 11,011 63,956 52,945
STAT heap block compress 874 61,708 60,834
STAT buffer is not pinned count 86,317 160,201 73,884
STAT consistent gets - examination 86,736 192,435 105,699
LATCH object queue header operation 1,035,929 1,144,350 108,421
LATCH simulator hash latch 211,800 391,764 179,964
STAT consistent gets 646,728 871,857 225,129
STAT consistent gets from cache 646,728 871,857 225,129
STAT session uga memory 589,176 196,392 -392,784
STAT rollback changes - undo records appl 17,261 605,019 587,758
STAT session pga memory -589,824 196,608 786,432
STAT sorts (rows) 1,059,387 0 -1,059,387
STAT redo entries 206,557 1,398,485 1,191,928
LATCH redo allocation 207,047 1,400,983 1,193,936
STAT session pga memory max 1,245,184 0 -1,245,184
STAT session uga memory max 1,552,240 0 -1,552,240
LATCH row cache objects 52,805 1,815,887 1,763,082
STAT db block changes 411,059 2,730,365 2,319,306
STAT db block gets 635,474 3,822,157 3,186,683
STAT db block gets from cache 635,474 3,822,157 3,186,683
STAT session logical reads 1,282,202 4,694,014 3,411,812
LATCH cache buffers chains 3,925,676 15,766,434 11,840,758
STAT physical read bytes ############ ############ 38,240,256
STAT physical read total bytes ############ ############ 38,240,256
STAT undo change vector size 17,324,196 86,289,444 68,965,248
STAT redo size 55,783,336 590,974,196 535,190,860
--------------------------------------------------------------------------------
3. Latching report
--------------------------------------------------------------------------------
Run1 used 5,661,226 latches
Run2 used 20,802,720 latches
Run1 used 72,8% fewer latches than Run2
================================================================================
End of report
================================================================================
And looking into the trace of both functions shows :
For the normal loop:
INSERT INTO BS_LOOP (BS_AT_AT_SE_SE_AG_AG_WG, BS_AT_AT_SE_SE_AG_AG_NO,
BS_AT_AT_SE_SE_NO, BS_AT_AT_NO, BSDOC_JAHR, BSDOC_MON, BSDOC_ZEN,
BSDOC_ANFBST, BSDOC_PLUS, BSDOC_ASMU, BSDOC_ASOU, BSDOC_EKUMS, BSDOC_VKUMS,
BSDOC_INVEK, BSDOC_DIFF, BSDOC_USER, BSDOC_AEND, BSDOC_PERIODE, BSDOC_GEK)
VALUES
(:B12 , :B11 , :B10 , :B9 , :B8 , :B7 , :B6 , :B5 , 0, 0, 0, 0, 0, :B1 , :B1
, :B4 , :B3 , :B2 , :B1 )
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 50784 10.81 11.15 343 417 600947 33523
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 50785 10.81 11.15 343 417 600947 33523
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 46 (recursive depth: 1)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 343 0.00 0.00
undo segment extension 5774 0.00 0.01
buffer busy waits 8 0.00 0.00
log file switch completion 2 0.22 0.38
********************************************************************************
and for the forall:
INSERT INTO BS_BULK ( BS_AT_AT_SE_SE_AG_AG_WG,
BS_AT_AT_SE_SE_AG_AG_NO, BS_AT_AT_SE_SE_NO, BS_AT_AT_NO, BSDOC_JAHR,
BSDOC_MON, BSDOC_ZEN, BSDOC_ANFBST, BSDOC_PLUS, BSDOC_ASMU, BSDOC_ASOU,
BSDOC_EKUMS, BSDOC_VKUMS, BSDOC_ABCU, BSDOC_ABCE, BSDOC_ABCD, BSDOC_USER,
BSDOC_AEND, BSDOC_INVMG, BSDOC_INVEK, BSDOC_INVD, BSDOC_DIFF, BSDOC_PERIODE,
VID, BSDOC_GEK )
VALUES
( :B1 , :B2 , :B3 , :B4 , :B25 , :B24 , :B5 , :B6 , :B7 , :B8 , :B9 , :B10 ,
:B11 , :B12 , :B13 , :B14 , :B15 , :B16 , :B17 , :B18 , :B19 , :B20 , :B23 ,
:B21 , :B22 )
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 49 0.00 0.00 0 0 0 0
Execute 80 42.60 53.23 5943 120974 3822157 37042
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 129 42.60 53.23 5943 120974 3822157 37042
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 46 (recursive depth: 1)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 5943 0.00 0.08
log file switch completion 26 0.98 7.33
log file switch (checkpoint incomplete) 10 0.97 3.99
So everything seems to belong to cpu-time, but why?
And, even more important, what can i do to reach my goal to execute it faster than the normal loop does.
Thx and sorry for this long post. I hope everything is readable.
Jörg
Edited by: anton1968 on 04.09.2010 12:04