Monday, June 01, 2009

single INSERT vs array BULK INSERT

Goal
----
Compare the performance of single INSERT vs array BULK INSERT.

Result
------
After you run benchmark a few more times, you will get about same result as I saw.

Bulk DML spend 20% more CPU time,
Latches are about same. No big difference.
db block gets, physical reads, consistent gets, session logical reads are all about same.
Bulk DML take 2MB more session pga memory is expected, to cache association array (1200 bytes * 1000 rows) in shared_pool memory. no big deal.

Conclusion
-----------
Consider single SQL first.
Only when the data process logic is too complicated, we may go with Bulk DML, there will be a little performance impact, e.g. 20% more CPU used.

Notes: Thanks for Tom Kyte pointing out the design strategy.
(http://mujiang.blogspot.com/2011/06/question-to-asktom-in-oracle-magazine.html)

Reference
---------
Oracle® Database PL/SQL Language Reference
11g Release 1 (11.1)
12 Tuning PL/SQL Applications for Performance

Reducing Loop Overhead for DML Statements and Queries with Bulk SQL.

* Running One DML Statement Multiple Times (FORALL Statement)
* Retrieving Query Results into Collections (BULK COLLECT Clause)

Setup
-----
drop table listing_wide purge;
create table listing_wide
(
vendor_id   number(10,0)  Not Null ,
listing_id   number(20,0)  Not Null ,
match_col               varchar2(1)     Not Null ,
vendor_listing_id  VarChar2(40)  Not Null ,
hash_lite         varchar2(32) ,
hash_code  VarChar2(32) ,
qty   number(5,0)  Not Null  ,
price  number(10,2) Not Null  ,
create_date Date default sysdate Not Null ,
update_date Date default sysdate Not Null ,
bsa_vend  Varchar2(30)     ,
isbn_raw  Varchar2(25)             ,
subject  Varchar2(2000)    ,
author   varchar2(750)     ,
title  varchar2(750)   ,
vend_catalog varchar2(255)   ,
description varchar2(4000) 
)
NOLOGGING
PARTITION BY LIST (vendor_id) 
(  
PARTITION v2134736  values( 2134736 ),
PARTITION v8408184  values( 8408184 ),
PARTITION v1  values( 1 ),
PARTITION v2  values( 2 ),
PARTITION vendor_NULL  VALUES (NULL),
PARTITION vendor_small VALUES (DEFAULT)
)
NOCOMPRESS 
NOPARALLEL
ENABLE ROW MOVEMENT;

drop table listing_purge;
create table listing_purge
NOLOGGING
PARTITION BY LIST (vendor_id) 
(  
PARTITION v2134736  values( 2134736 ),
PARTITION v8408184  values( 8408184 ),
PARTITION v1  values( 1 ),
PARTITION v2  values( 2 ),
PARTITION vendor_NULL  VALUES (NULL),
PARTITION vendor_small VALUES (DEFAULT)
)
as
select a.* 
from listing_wide a
where 1=0;

alter table listing_purge modify (
create_date Date default sysdate ,
update_date Date default sysdate 
);


Test
----

truncate table listing_wide;
truncate table listing_purge;

insert /*+ append */ into listing_purge 
(listing_id, vendor_id, price, qty,hash_lite, hash_code, vendor_listing_id, author, title,subject,isbn_raw, bsa_vend
,match_col)
select
rownum listing_id, 
mod(rownum,2) + 1 vendor_id,
1.11 price,
10 qty,
rpad('x',31,'x') hash_lite,
rpad('x',31,'x') hash_code,
rownum vendor_listing_id,
rpad(rownum,400,'x') author,
rpad('x',400,'x') title,
rpad('x',300,'x') subject,
rownum isbn_raw,
mod(rownum,100)||','||mod(Round(rownum/10),100) bsa_vend
,'x' match_col
from dual
connect by level <= 80100;

commit;

set serveroutput on
set linesize 200
begin
tmp_benchmark;
end;
/

select vendor_id, count(*) from listing_wide
group by vendor_id;

select vendor_id, count(*) from listing_purge
group by vendor_id;


Code
----
CREATE OR REPLACE procedure tmp_benchmark
as
l_cnt number := 0; l_upd_rows number := 0;
l_fetch_limit PLS_INTEGER := 1000;

cursor c2 is
select listing_id, vendor_id, price, qty,hash_lite, hash_code, vendor_listing_id, author, title,subject,isbn_raw, bsa_vend, match_col
from listing_purge partition (v2);

TYPE listing_purge_tab is table of c2%rowtype;
lt_book listing_purge_tab;

BEGIN

runStats_pkg.rs_start;

INSERT INTO listing_wide
(listing_id, vendor_id, price, qty,hash_lite, hash_code, vendor_listing_id, author, title,subject,isbn_raw, bsa_vend, match_col)
select listing_id, vendor_id, price, qty,hash_lite, hash_code, vendor_listing_id, author, title,subject,isbn_raw, bsa_vend, match_col
from listing_purge partition (v1);

commit;

runStats_pkg.rs_middle;

-- Open cursor 
OPEN c2;

LOOP
fetch c2 BULK COLLECT INTO lt_book LIMIT l_fetch_limit;

FORALL j IN lt_book.FIRST..lt_book.LAST
INSERT into listing_wide
(listing_id, vendor_id, price, qty,hash_lite, hash_code, vendor_listing_id, author, title,subject,isbn_raw, bsa_vend, match_col)
values (lt_book(j).listing_id, lt_book(j).vendor_id, lt_book(j).price, lt_book(j).qty, lt_book(j).hash_lite, lt_book(j).hash_code, 
lt_book(j).vendor_listing_id, lt_book(j).author, lt_book(j).title, lt_book(j).subject, lt_book(j).isbn_raw, lt_book(j).bsa_vend
, lt_book(j).match_col)
;

l_upd_rows := l_upd_rows + SQL%RowCount;

exit when lt_book.COUNT < l_fetch_limit;
--exit when c2%notfound;

END LOOP;
close c2;

commit;

runStats_pkg.rs_stop;

EXCEPTION
WHEN others THEN
--u$err.err;
raise;
END;
/

RunStats
--------
Run1 ran in 669 hsecs
Run2 ran in 914 hsecs
run 1 ran in 73.19% of the time

Name                                  Run1        Run2        Diff
STAT...parse count (hard)                2           3           1
LATCH.DML lock allocation              328         327          -1
STAT...sorts (memory)                    1           0          -1
STAT...parse time cpu                    2           0          -2
LATCH.internal temp table obje           4           2          -2
LATCH.shared pool simulator              6           8           2
LATCH.ASM db client latch                4           6           2
STAT...enqueue releases              1,222       1,224           2
LATCH.space background task la           7           5          -2
STAT...redo log space requests           0           2           2
STAT...Heap Segment Array Upda         146         148           2
STAT...Heap Segment Array Inse          12          14           2
STAT...HSC Heap Segment Block       50,222      50,224           2
STAT...index scans kdiixs1              98          96          -2
STAT...enqueue requests              1,220       1,224           4
STAT...application wait time             0           4           4
STAT...physical read total mul         153         148          -5
STAT...redo ordering marks           1,121       1,126           5
STAT...messages sent                    97         105           8
STAT...session logical reads       147,017     147,029          12
STAT...commit cleanouts              3,364       3,376          12
STAT...consistent changes               24          38          14
STAT...db block changes            154,297     154,313          16
LATCH.Consistent RBA                    96          80         -16
STAT...parse time elapsed               67          51         -16
LATCH.lgwr LWN SCN                      97          78         -19
STAT...redo entries                102,505     102,524          19
STAT...redo buffer allocation            0          22          22
LATCH.post/wait queue                    1          31          30
STAT...recursive cpu usage              91         121          30
STAT...redo log space wait tim           0          30          30
STAT...CPU used by this sessio          91         125          34
LATCH.session allocation             7,536       7,574          38
LATCH.In memory undo latch               9          48          39
STAT...physical read total IO          275         235         -40
LATCH.row cache objects              2,688       2,642         -46
STAT...execute count                   261         310          49
STAT...consistent gets              19,683      19,632         -51
LATCH.shared pool                      138         196          58
STAT...db block gets               127,334     127,397          63
LATCH.undo global data               8,608       8,537         -71
STAT...active txn count during       8,180       8,107         -73
STAT...recursive calls               3,858       3,941          83
LATCH.enqueues                       2,034       2,132          98
STAT...user I/O wait time              564         670         106
LATCH.enqueue hash chains            2,525       2,634         109
STAT...table scan rows gotten       50,445      50,315        -130
LATCH.MinActiveScn Latch            16,931      16,796        -135
LATCH.redo allocation                  295         467         172
STAT...physical reads               10,010      10,194         184
STAT...Number of read IOs issu           0         184         184
LATCH.cache table scan latch           231          19        -212
STAT...Elapsed Time                    669         920         251
STAT...undo change vector size   3,185,292   3,185,592         300
LATCH.redo writing                     295         709         414
LATCH.multiblock read objects          464          38        -426
LATCH.object queue header heap           3         451         448
LATCH.active checkpoint queue            2         457         455
LATCH.messages                         368       1,250         882
LATCH.cache buffer handles          15,010      13,714      -1,296
STAT...free buffer inspected        10,054      11,522       1,468
LATCH.cache buffers lru chain       20,881      22,578       1,697
LATCH.simulator hash latch          13,132      10,817      -2,315
STAT...hot buffers moved to he         560       3,105       2,545
STAT...IMU Redo allocation siz       8,236      11,044       2,808
STAT...dirty buffers inspected           1       4,860       4,859
LATCH.checkpoint queue latch           201       7,974       7,773
LATCH.cache buffers chains         545,026     536,670      -8,356
LATCH.object queue header oper      34,953      44,292       9,339
STAT...physical reads cache pr       9,735         133      -9,602
STAT...free buffer requested        20,720      10,987      -9,733
STAT...consistent gets from ca      10,729         959      -9,770
STAT...physical reads cache         10,010         184      -9,826
STAT...physical reads direct             0      10,010      10,010
STAT...consistent gets direct            0      10,010      10,010
STAT...consistent gets from ca      19,683       9,622     -10,061
STAT...redo size                78,097,020  78,123,668      26,648
STAT...IMU undo allocation siz      52,228         908     -51,320
STAT...physical read total byt  82,001,920  83,509,248   1,507,328
STAT...physical IO disk bytes   82,001,920  83,509,248   1,507,328
STAT...cell physical IO interc  82,001,920  83,509,248   1,507,328
STAT...physical read bytes      82,001,920  83,509,248   1,507,328
STAT...session pga memory                0   2,162,688   2,162,688
STAT...Effective IO time                 0   6,195,022   6,195,022

Run1 latches total versus runs -- difference and pct
Run1        Run2        Diff       Pct
672,749     681,506       8,757     98.72%

PL/SQL procedure successfully completed.

2 comments:

Fahd Mirza said...

It was really nice to run this test myself.

Thanks for sharing this, and you should write more and regularly.

regards

Unknown said...

To Fahd Mirza,

Thanks for the encouragement.

-MJ