Bulk Collect/FORALL的性能测试

有同学在T.Askmaclean.com上提问关于bulk  collect /FORALL对性能的影响, 提问的内容是针对 bulk collect后FORALL批量INSERT 和 直接使用SQL语句INSERT SELECT间的对比。

 

AS maclean Answered:

1.

bulk collect 主要用在批量 填充 队列变量,这些array/table 变量可能最后用于打印数据,对于INSERT 一般建议直接用SQL加上nologging +append 优化

例如:
Cur_Num number := DBMS_Sql.Open_Cursor();
rc Sys_Refcursor;

cursor e is select Employee_ID, First_Name, Last_Name
from Employees;
type Emps_t is table of e%rowtype;
Emps Emps_t;
begin
DBMS_Sql.Parse(
c=>Cur_Num, Language_Flag=>DBMS_Sql.Native, Statement=>
‘select Employee_ID, First_Name, Last_Name
from Employees
where Department_ID = :d and Salary > :s and …’);

DBMS_Sql.Bind_Variable(Cur_Num, ‘:d’, Department_ID);
DBMS_Sql.Bind_Variable(Cur_Num, ‘:s’, Salary);

Dummy := DBMS_Sql.Execute(Cur_Num);
— Switch to ref cursor and native dynamic SQL
rc := DBMS_Sql.To_Refcursor(Cur_Num);

  fetch rc bulk collect into Emps;
  close rc;

以上利用  bulk collect 批量填充了Emps这张PL/SQL 表,之后会将Emps输出到终端

2.

An ORA-22813 when using BULK COLLECT is typically expected behavior indicating that you have exceeded the amount of free memory in the PGA.  As collections are processed by PL/SQL they use the PGA to store their memory structures.  Depending on the LIMIT size of the BULK COLLECT and additional processing of the collected data you may exceed the free memory of the PGA.  While intuitively you may think that increasing the PGA memory and increasing the LIMIT size will increase performance, the following example shows you that this is not true in this case.  So, by reviewing this example you should be able to strike a balance between a reasonable LIMIT size and the size of the PGA while maintaining a high level of performance using BULK COLLECT.

 

合理设置limit size确实可以 避免PGA overflow  避免出现ORA-22813 错误

 

[oracle@vrh8 ~]$ oerr ora 22813
22813, 00000, “operand value exceeds system limits”
// *Cause:  Object or Collection value was too large. The size of the value
//          might have exceeded 30k in a SORT context, or the size might be
//          too big for available memory.
// *Action:  Choose another value and retry the operation.

 

 

这里我们姑且不谈bulk collect/forall 和直接使用SQL  INSERT ..SELECT间的性能对比,而来看看 bulk collect/forall 与 普通的 fetch 、FOR LOOP的性能对比

 

 

SQL> select * from v$version;

BANNER
----------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.5.0 - 64bi
PL/SQL Release 10.2.0.5.0 - Production
CORE    10.2.0.5.0      Production
TNS for Linux: Version 10.2.0.5.0 - Production
NLSRTL Version 10.2.0.5.0 - Production

SQL> 
SQL> 
SQL> select * from global_name;

GLOBAL_NAME
--------------------------------------------------------------------------------
www.oracledatabase12g.com

SQL> create table maclean_forall tablespace users as select * from dba_objects;

Table created.

SQL> create table maclean_forall2 tablespace users as select * from dba_objects where rownum=0;

Table created.

INSERT DATA:

SQL> select count(*) from maclean_forall;

  COUNT(*)
----------
    815200

SQL> select count(*) from maclean_forall2;

  COUNT(*)
----------
         0

SQL> alter table maclean_forall nologging;

Table altered.

SQL> alter table maclean_forall2 nologging;

Table altered.

SQL> set timing on;
SQL> select  st.name,ss.value from v$mystat ss, v$statname st 
  2  where ss.statistic# = st.statistic#                 
  3  and st.name in ('redo size','undo change vector size','CPU used by this session');

NAME                                                                  VALUE
---------------------------------------------------------------- ----------
CPU used by this session                                                  1
redo size                                                                 0
undo change vector size                                                   0

Elapsed: 00:00:00.00
SQL> 
SQL> 

SQL> oradebug setmypid;
Statement processed.
SQL> oradebug event 10046 trace name context forever,level 8;
Statement processed.
SQL> 
SQL> declare
  2     type recstartyp is table of maclean_forall%rowtype index by BINARY_INTEGER;
  3     rec_tab recstartyp;
  4     cursor temp is select * from maclean_forall;
  5  begin
  6     open temp;
  7     fetch temp bulk collect into rec_tab;
  8     FORALL i in rec_tab.first..rec_tab.last
  9        insert /*+ append */  into maclean_forall2 values rec_tab(i);
 10     commit;
 11     close temp;
 12  end;
 13  /

PL/SQL procedure successfully completed.

Elapsed: 00:00:10.00
SQL> 
SQL> oradebug event 10046 trace name context off;
Statement processed.
SQL> oradebug tracefile_name
/s01/admin/G10R25/udump/g10r25_ora_24477.trc
SQL> 
SQL> select  st.name,ss.value from v$mystat ss, v$statname st 
  2  where ss.statistic# = st.statistic#                 
  3  and st.name in ('redo size','undo change vector size','CPU used by this session');

NAME                                                                  VALUE
---------------------------------------------------------------- ----------
CPU used by this session                                                436
redo size                                                          91943804
undo change vector size                                             3572052

Elapsed: 00:00:00.01

SELECT *
FROM
 MACLEAN_FORALL

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          1          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      2.05       2.01       7275      11266          0      815200
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      2.06       2.01       7275      11267          0      815200

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS   (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
 815200  TABLE ACCESS FULL MACLEAN_FORALL (cr=11266 pr=7275 pw=0 time=14673632 us)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file scattered read                        512        0.00          0.03
  db file sequential read                         3        0.00          0.00
********************************************************************************

INSERT /*+ append */ INTO MACLEAN_FORALL2
VALUES
 (:B1 ,:B2 ,:B3 ,:B4 ,:B5 ,:B6 ,:B7 ,:B8 ,:B9 ,:B10 ,:B11 ,:B12 ,:B13 )

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      2.17       7.57      11805      22071     113084      815200
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      2.17       7.57      11805      22071     113084      815200

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS   (recursive depth: 1)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                     11805        0.01          0.19
  log file switch completion                      2        0.64          1.04
  log file switch (checkpoint incomplete)         9        0.97          2.95
  flashback buf free by RVWR                      6        0.10          0.15
  latch: cache buffers lru chain                  2        0.00          0.00

 解析1次 执行1次   cpu time= 2.06 +  2.17=4.23s 
 redo size 91943804    87MB          undo 3572052

elapsed time= 7.57+ 2.01=9.58s 

SQL> select  st.name,ss.value from v$mystat ss, v$statname st 
  2  where ss.statistic# = st.statistic#                 
  3  and st.name in ('redo size','undo change vector size','CPU used by this session');

NAME                                                                  VALUE
---------------------------------------------------------------- ----------
CPU used by this session                                                  0
redo size                                                                 0
undo change vector size                                                   0

SQL> oradebug setmypid;
Statement processed.
SQL> oradebug event 10046 trace name context forever,level 8;
Statement processed.
SQL> 
SQL> set timing on;
SQL> 
SQL> 
SQL> 
SQL> declare
  2     type recstartyp is table of maclean_forall%rowtype index by BINARY_INTEGER;
  3     rec_tab recstartyp;
  4     cursor temp is select * from maclean_forall;
  5  begin
  6     open temp;
  7     fetch temp bulk collect into rec_tab;
  8     FORALL i in rec_tab.first..rec_tab.last
  9        insert  into maclean_forall2 values rec_tab(i);
 10     commit;
 11     close temp;
 12  end;
 13  /

PL/SQL procedure successfully completed.

Elapsed: 00:00:09.34
SQL> 
SQL> oradebug event 10046 trace name context off;
Statement processed.
SQL> oradebug tracefile_name
/s01/admin/G10R25/udump/g10r25_ora_24609.trc
SQL> 
SQL> 
SQL> select  st.name,ss.value from v$mystat ss, v$statname st 
  2  where ss.statistic# = st.statistic#                 
  3  and st.name in ('redo size','undo change vector size','CPU used by this session');

NAME                                                                  VALUE
---------------------------------------------------------------- ----------
CPU used by this session                                                455
redo size                                                          91679440
undo change vector size                                             3518580

Elapsed: 00:00:00.00

declare
   type recstartyp is table of maclean_forall%rowtype index by BINARY_INTEGER;
   rec_tab recstartyp;
   cursor temp is select * from maclean_forall;
begin
   open temp;
   fetch temp bulk collect into rec_tab;
   FORALL i in rec_tab.first..rec_tab.last
      insert  into maclean_forall2 values rec_tab(i);
   commit;
   close temp;
end;

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.04       0.04          0      32975     108697           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.05       0.05          0      32975     108697           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS

SELECT *
FROM
 MACLEAN_FORALL

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      1.98       1.94       5629      11270          0      815200
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      1.98       1.94       5629      11270          0      815200

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: SYS   (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
 815200  TABLE ACCESS FULL MACLEAN_FORALL (cr=11270 pr=5629 pw=0 time=15488945 us)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                         7        0.00          0.00
  db file scattered read                        356        0.00          0.01
********************************************************************************

INSERT INTO MACLEAN_FORALL2
VALUES
 (:B1 ,:B2 ,:B3 ,:B4 ,:B5 ,:B6 ,:B7 ,:B8 ,:B9 ,:B10 ,:B11 ,:B12 ,:B13 )

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      2.43       7.07      11328      21705     108696      815200
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      2.44       7.07      11328      21705     108696      815200

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS   (recursive depth: 1)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  log file switch completion                      4        0.40          0.41
  db file sequential read                     11328        0.41          3.91
  latch: cache buffers lru chain                  5        0.00          0.00
  log file switch (checkpoint incomplete)         3        0.00          0.00

解析1次 执行1次!

cpu time= 2.43 +  1.98 =4.41 s 

redo size  91679440   undo change vector size   3518580

elapsed = 7.07 + 1.94= 9.01

在以上测试中 PL/SQL部分仅占用 0.05 s的CPU TIME 

SQL>  set timing on;
SQL> select  st.name,ss.value from v$mystat ss, v$statname st 
  2  where ss.statistic# = st.statistic#                 
  3  and st.name in ('redo size','undo change vector size','CPU used by this session');

NAME                                                                  VALUE
---------------------------------------------------------------- ----------
CPU used by this session                                                  1
redo size                                                                 0
undo change vector size                                                   0

Elapsed: 00:00:00.01
SQL> 
SQL> 
SQL> 
SQL> oradebug setmypid;
Statement processed.
SQL> oradebug event 10046 trace name context forever,level 8;
Statement processed.
SQL> 
SQL> 
SQL> declare
  2  
  3     cursor temp is select * from maclean_forall;
  4  begin
  5  
  6    for i in temp loop
  7    insert into maclean_forall2 values i;
  8    end loop;
  9    commit;
 10  end;
 11  /

PL/SQL procedure successfully completed.

Elapsed: 00:01:07.18
SQL> 
SQL> 
SQL> 
SQL> oradebug event 10046 trace name context off;
Statement processed.
SQL> oradebug tracefile_name
/s01/admin/G10R25/udump/g10r25_ora_24804.trc
SQL> 
SQL> select  st.name,ss.value from v$mystat ss, v$statname st 
  2  where ss.statistic# = st.statistic#                 
  3  and st.name in ('redo size','undo change vector size','CPU used by this session');

NAME                                                                  VALUE
---------------------------------------------------------------- ----------
CPU used by this session                                               5599
redo size                                                         318363048
undo change vector size                                            74972216

Elapsed: 00:00:00.00

declare
   cursor temp is select * from maclean_forall;
begin
  for i in temp loop
  insert into maclean_forall2 values i;
  end loop;
  commit;
end;

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1     44.79      31.48      31534      32491     940113           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2     44.80      31.49      31534      32491     940113           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  log file sync                                   1        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        4.83          4.83

SELECT *
FROM
 MACLEAN_FORALL

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     8153      1.02       1.57      10499      19310          0      815200
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total     8155      1.02       1.57      10499      19310          0      815200

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: SYS   (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
 815200  TABLE ACCESS FULL MACLEAN_FORALL (cr=19310 pr=10499 pw=0 time=6523808 us)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file scattered read                        667        0.00          0.03
********************************************************************************

INSERT INTO MACLEAN_FORALL2
VALUES
 (:B1 ,:B2 ,:B3 ,:B4 ,:B5 ,:B6 ,:B7 ,:B8 ,:B9 ,:B10 ,:B11 ,:B12 ,:B13 )

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute 815200     10.10      32.48      21035      13181     940112      815200
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   815201     10.10      32.48      21035      13181     940112      815200

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS   (recursive depth: 1)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                     21034        0.63          3.25
  log file switch completion                      9        0.93          2.06
  log file switch (checkpoint incomplete)        18        0.97          4.92
  latch: library cache lock                       1        0.00          0.00
********************************************************************************


游标查询 MACLEAN_FORALL  执行一次 但fetch了 8153次, insert共执行了 815200次 , 
最离谱的是Pl/SQL 引擎和SQL引擎之间的切换大约消耗了30s 


cpu time = 32.48+ 1.57 + 31.48 = 65s 
redo size= 318363048 bytes = 303 MB

 

 

就以上测试可以得出以上结论:

1. FORALL执行使用 原本需要大量循环完成的工作在一次Execute内完成,节省了大量的CPU TIME(大约78%)。
2. append对 forall INSERT起不到减少redo的作用,但是FORALL INSERT本身对比普通loop insert节省了大量redo (大约71%) 和 大量的undo (大约95%)的undo
3. 使用FOR ALL的代价是消耗大量的PGA内存
4. 大量循环LOOP,从Pl/SQL引擎到SQL引擎的切换的消耗是巨大的,几乎占用了以上测试中50%的CPU TIME , 而FOR ALL/Bulk collect恰恰可以避免这种切换。

 

PS: 直接使用INSERT /*+ APPEND */ INTO SELECT的性能测试:

 

 

SQL> set timing on;
SQL> select  st.name,ss.value from v$mystat ss, v$statname st 
  2  where ss.statistic# = st.statistic#                 
  3  and st.name in ('redo size','undo change vector size','CPU used by this session');

NAME                                                                  VALUE
---------------------------------------------------------------- ----------
CPU used by this session                                                  1
redo size                                                                 0
undo change vector size                                                   0

Elapsed: 00:00:00.00
SQL> oradebug setmypid;
Statement processed.
SQL> oradebug event 10046 trace name context forever,level 8;
Statement processed.
SQL> 
SQL> insert /*+ append */  into maclean_forall2 select * from maclean_forall;

815200 rows created.

Elapsed: 00:00:02.27
SQL> oradebug event 10046 trace name context off;
Statement processed.
SQL> oradebug tracefile_name
/s01/admin/G10R25/udump/g10r25_ora_25621.trc
SQL> 
SQL> 
SQL> select  st.name,ss.value from v$mystat ss, v$statname st 
  2  where ss.statistic# = st.statistic#                 
  3  and st.name in ('redo size','undo change vector size','CPU used by this session');

NAME                                                                  VALUE
---------------------------------------------------------------- ----------
CPU used by this session                                                103
redo size                                                            260168
undo change vector size                                               57544

insert /*+ append */  into maclean_forall2 select * from maclean_forall

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          1          0           0
Execute      1      0.99       2.18      21619      12238      13865      815200
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      1.00       2.19      21619      12239      13865      815200

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  LOAD AS SELECT  (cr=12238 pr=21619 pw=11206 time=2187590 us)
 815200   TABLE ACCESS FULL MACLEAN_FORALL (cr=11267 pr=10263 pw=0 time=6521656 us)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                       155        0.00          0.00
  flashback buf free by RVWR                     28        0.12          1.15
  db file scattered read                        701        0.00          0.04
  direct path write                               2        0.00          0.00
  direct path sync                                1        0.02          0.02
  control file sequential read                    8        0.00          0.00
  control file parallel write                     4        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        7.32          7.32

 

 

 

直接SQL INSERT..SELECT 的性能还是要好过bulk collect/FORALL的, 正如Tom kyte所说:”如果可能,尽量利用一条SQL语句完成工作。如果无法用一条SQL语句完成,就通过PL/SQL实现(不过,尽可能少用PL/SQL!)。如果在PL/SQL中也无法做到(因为它缺少一些特性,如列出目录中的文件),可以试试使用Java存储过程来实现。如果Java还办不到,那就C外部存储过程中实现。如果速度要求很高,或者要使用采用C编写的一个第三方API,就常常使用这种方法。如果在C外部例程中还无法实现,你就该好好想想有没有必要做这个工作了。”