We are noticing that large table inserts with CLOB is taking more time on 12c than 11g. The inserts are during an online transaction processing where we copy data from one business unit to another. There is one table in particular that is taking considerably longer. To debug this, I created a simple Insert script on a generic table
SET LINESIZE 200
SET SERVEROUTPUT ON
set timing on
set time on
set echo on
SELECT SYSTIMESTAMP FROM DUAL;
column PRODUCT format a45
column version format a12
SELECT product,version FROM PRODUCT_COMPONENT_VERSION where upper(Product) like 'ORACLE%' ;
CREATE TABLE TMP_TEST_LARGE_ROWS_CLOB
(ID NUMBER, CLOB_VALUE CLOB, RANDOM_STRING VARCHAR2(100));
BEGIN
FOR i IN 1..1000 LOOP
INSERT INTO TMP_TEST_LARGE_ROWS_CLOB
(id, clob_value,random_string)
select
i*rownum id,
DBMS_RANDOM.string ('B', 500),
DBMS_RANDOM.string('A', 20)
from dual
CONNECT BY rownum <= 1000 ;
COMMIT;
END LOOP;
END ;
/
Here are the results in both 11g and 12c.
11g
21:49:41 SQL> SELECT SYSTIMESTAMP FROM DUAL;
SYSTIMESTAMP
---------------------------------------------------------------------------
26-AUG-17 09.49.41.912231 PM -07:00
Elapsed: 00:00:00.02
21:49:41 SQL>
21:49:41 SQL> column PRODUCT format a45
21:49:41 SQL> column version format a12
21:49:41 SQL> SELECT product,version FROM PRODUCT_COMPONENT_VERSION where upper(Product) like 'ORACLE%' ;
PRODUCT VERSION
--------------------------------------------- ------------
Oracle Database 11g Enterprise Edition 11.2.0.3.0
Elapsed: 00:00:00.10
21:49:42 SQL>
21:49:42 SQL>
21:49:42 SQL> CREATE TABLE TMP_TEST_LARGE_ROWS_CLOB
21:49:42 2 (ID NUMBER, CLOB_VALUE CLOB, RANDOM_STRING VARCHAR2(100));
Table created.
Elapsed: 00:00:00.26
21:49:42 SQL>
21:49:42 SQL> BEGIN
21:49:42 2 FOR i IN 1..1000 LOOP
21:49:42 3 INSERT INTO TMP_TEST_LARGE_ROWS_CLOB
21:49:42 4 (id, clob_value,random_string)
21:49:42 5 select
21:49:42 6 i*rownum id,
21:49:42 7 DBMS_RANDOM.string ('B', 500),
21:49:42 8 DBMS_RANDOM.string('A', 20)
21:49:42 9 from dual
21:49:42 10 CONNECT BY rownum <= 1000 ;
21:49:42 11 COMMIT;
21:49:42 12 END LOOP;
21:49:42 13 END ;
21:49:42 14 /
PL/SQL procedure successfully completed.
Elapsed: 00:14:47.99
22:04:30 SQL>
22:04:30 SQL> spool off
12c
21:51:10 SQL> SELECT SYSTIMESTAMP FROM DUAL;
SYSTIMESTAMP
---------------------------------------------------------------------------
26-AUG-17 09.51.10.638013 PM -07:00
Elapsed: 00:00:00.00
21:51:10 SQL>
21:51:10 SQL> column PRODUCT format a45
21:51:10 SQL> column version format a12
21:51:10 SQL> SELECT product,version FROM PRODUCT_COMPONENT_VERSION where upper(Product) like 'ORACLE%' ;
PRODUCT VERSION
--------------------------------------------- ------------
Oracle Database 12c Enterprise Edition 12.1.0.2.0
Elapsed: 00:00:00.01
21:51:10 SQL>
21:51:10 SQL>
21:51:10 SQL> CREATE TABLE TMP_TEST_LARGE_ROWS_CLOB
21:51:10 2 (ID NUMBER, CLOB_VALUE CLOB, RANDOM_STRING VARCHAR2(100));
Table created.
Elapsed: 00:00:00.02
21:51:10 SQL>
21:51:10 SQL> BEGIN
21:51:10 2 FOR i IN 1..1000 LOOP
21:51:10 3 INSERT INTO TMP_TEST_LARGE_ROWS_CLOB
21:51:10 4 (id, clob_value,random_string)
21:51:10 5 select
21:51:10 6 i*rownum id,
21:51:10 7 DBMS_RANDOM.string ('B', 500),
21:51:10 8 DBMS_RANDOM.string('A', 20)
21:51:10 9 from dual
21:51:10 10 CONNECT BY rownum <= 1000 ;
21:51:10 11 COMMIT;
21:51:10 12 END LOOP;
21:51:10 13 END ;
21:51:10 14 /
PL/SQL procedure successfully completed.
Elapsed: 00:46:05.83
22:37:16 SQL> spool off
Again, this is just an example, just to show that creating a million rows in a loop is considerably slower in 12c than 11g. The actual table where we are facing:
- Has FK references and hence cannot use APPEND hint. Also has a couple of triggers
- The table is updated in multiple ways from the UI - either 1 or 2 rows inserts or during a business unit copy , where records are inserted in BULK using Insert... select ... clause.
Additional Info:
I am not able to paste all the parameters from v$parameter since it exceeds 20000 characters. I can provide the values for any specific set of parameters if needed.
We want to migrate to 12c asap and do not want to change a lot of such Inserts, which are inside various PL/SQL package procedures.
Any help or pointers on why it is taking more time would be appreciated.
In our test instances where I got the above results, the 12c instance has more memory and sga size
12C:
sga_max_size 85899345920
sga_target 85899345920
11g:
sga_max_size 10737418240
sga_target 10737418240
As requested, here is the additional information.
11g
SQL> SELECT product,version FROM PRODUCT_COMPONENT_VERSION where upper(Product) like 'ORACLE%' ;
PRODUCT VERSION
--------------------------------------------- ------------
Oracle Database 11g Enterprise Edition 11.2.0.3.0
SQL>
SQL> select dbms_metadata.get_ddl('TABLE','TMP_TEST_LARGE_ROWS_CLOB',user) from dual;
DBMS_METADATA.GET_DDL('TABLE','TMP_TEST_LARGE_ROWS_CLOB',USER)
--------------------------------------------------------------------------------
CREATE TABLE "APP"."TMP_TEST_LARGE_ROWS_CLOB"
( "ID" NUMBER,
"CLOB_VALUE" CLOB,
"RANDOM_STRING" VARCHAR2(100)
) SEGMENT CREATION IMMEDIATE
PCTFREE 10 PCTUSED 40 INITRANS 1 MAXTRANS 255
NOCOMPRESS NOLOGGING
STORAGE(INITIAL 1048576 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1
BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT)
TABLESPACE "APP_DAT"
LOB ("CLOB_VALUE") STORE AS BASICFILE (
TABLESPACE "APP_DAT" ENABLE STORAGE IN ROW CHUNK 16384 RETENTION
NOCACHE NOLOGGING
STORAGE(INITIAL 1048576 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1
BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT))
12c
SQL> SELECT product,version FROM PRODUCT_COMPONENT_VERSION where upper(Product) like 'ORACLE%' ;
PRODUCT VERSION
--------------------------------------------- ------------
Oracle Database 12c Enterprise Edition 12.1.0.2.0
SQL>
SQL> select dbms_metadata.get_ddl('TABLE','TMP_TEST_LARGE_ROWS_CLOB',user) from dual;
DBMS_METADATA.GET_DDL('TABLE','TMP_TEST_LARGE_ROWS_CLOB',USER)
--------------------------------------------------------------------------------
CREATE TABLE "APP"."TMP_TEST_LARGE_ROWS_CLOB"
( "ID" NUMBER,
"CLOB_VALUE" CLOB,
"RANDOM_STRING" VARCHAR2(100)
) SEGMENT CREATION IMMEDIATE
PCTFREE 10 PCTUSED 40 INITRANS 1 MAXTRANS 255
NOCOMPRESS NOLOGGING
STORAGE(INITIAL 1048576 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1
BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT)
TABLESPACE "APP_DAT"
LOB ("CLOB_VALUE") STORE AS SECUREFILE (
TABLESPACE "APP_DAT" ENABLE STORAGE IN ROW CHUNK 16384
NOCACHE NOLOGGING NOCOMPRESS KEEP_DUPLICATES
STORAGE(INITIAL 1048576 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
PCTINCREASE 0
BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT))
Can you do this for us please in each environment
set long 50000
select dbms_metadata.get_ddl('TABLE','TMP_TEST_LARGE_ROWS_CLOB',user) from dual
We need to see how those clobs are created/stored
==================
Sorry to take so long to get back to you. I did these tests with basicfile and securefile - and there was not much difference between the two. Similarly, I did not see the marked difference between 11 and 12.1. But there was a marked improvement with 12.2, so thats probably my recommendation. These all done on the same machine.
11.2.0.4
========
SQL> CREATE TABLE "TMP_TEST_LARGE_ROWS_CLOB"
2 ( "ID" NUMBER,
3 "CLOB_VALUE" CLOB,
4 "RANDOM_STRING" VARCHAR2(100)
5 ) SEGMENT CREATION IMMEDIATE
6 PCTFREE 10 PCTUSED 40 INITRANS 1 MAXTRANS 255
7 NOCOMPRESS NOLOGGING
8 STORAGE(INITIAL 1048576 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
9 PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1
10 BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT)
11 LOB ("CLOB_VALUE") STORE AS BASICFILE (
12 ENABLE STORAGE IN ROW CHUNK 16384 RETENTION
13 NOCACHE NOLOGGING
14 STORAGE(INITIAL 1048576 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
15 PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1
16 BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT))
17 /
Table created.
SQL>
SQL> set timing on
SQL> BEGIN
2 FOR i IN 1..100 LOOP
3 INSERT INTO TMP_TEST_LARGE_ROWS_CLOB
4 (id, clob_value,random_string)
5 select
6 i*rownum id,
7 DBMS_RANDOM.string ('B', 500),
8 DBMS_RANDOM.string('A', 20)
9 from dual
10 CONNECT BY rownum <= 1000 ;
11 COMMIT;
12 END LOOP;
13 END ;
14 /
PL/SQL procedure successfully completed.
Elapsed: 00:02:33.91
SQL> @sessev
EVENT TOTAL_WAITS TOTAL_TIMEOUTS SECS PCT
-------------------------------------------- ----------- -------------- ---------- -------
log file sync 3 0 0 00.00%
db file sequential read 3 0 0 00.00%
events in waitclass Other 9 0 0 00.00%
log file switch (checkpoint incomplete) 2 0 .01 00.01%
enq: RO - fast object reuse 3 0 .01 00.01%
log file switch (private strand flush incomp 2 0 .01 00.01%
lete)
Disk file operations I/O 3 0 .02 00.01%
CPU 153.74 99.97%
12.1.0.2
========
SQL> CREATE TABLE "TMP_TEST_LARGE_ROWS_CLOB"
2 ( "ID" NUMBER,
3 "CLOB_VALUE" CLOB,
4 "RANDOM_STRING" VARCHAR2(100)
5 ) SEGMENT CREATION IMMEDIATE
6 PCTFREE 10 PCTUSED 40 INITRANS 1 MAXTRANS 255
7 NOCOMPRESS NOLOGGING
8 STORAGE(INITIAL 1048576 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
9 PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1
10 BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT)
11 LOB ("CLOB_VALUE") STORE AS SECUREFILE (
12 ENABLE STORAGE IN ROW CHUNK 16384
13 NOCACHE NOLOGGING NOCOMPRESS KEEP_DUPLICATES
14 STORAGE(INITIAL 1048576 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
15 PCTINCREASE 0
16 BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT))
17 /
Table created.
SQL>
SQL> set timing on
SQL> BEGIN
2 FOR i IN 1..100 LOOP
3 INSERT INTO TMP_TEST_LARGE_ROWS_CLOB
4 (id, clob_value,random_string)
5 select
6 i*rownum id,
7 DBMS_RANDOM.string ('B', 500),
8 DBMS_RANDOM.string('A', 20)
9 from dual
10 CONNECT BY rownum <= 1000 ;
11 COMMIT;
12 END LOOP;
13 END ;
14 /
PL/SQL procedure successfully completed.
Elapsed: 00:02:46.10
SQL>
SQL> @sessev
EVENT TOTAL_WAITS TOTAL_TIMEOUTS SECS PCT
-------------------------------------------- ----------- -------------- ---------- -------
local write wait 4 0 0 00.00%
db file single write 1 0 0 00.00%
log file sync 2 0 0 00.00%
latch: cache buffers chains 1 0 0 00.00%
control file parallel write 3 0 0 00.00%
Data file init write 1 0 0 00.00%
events in waitclass Other 2 0 .01 00.01%
log file switch completion 1 0 .01 00.01%
control file sequential read 71 0 .02 00.01%
db file sequential read 270 0 .04 00.02%
Disk file operations I/O 16 0 .07 00.04%
CPU 166.5 99.91%
12.2.0.1
========
SQL> CREATE TABLE "TMP_TEST_LARGE_ROWS_CLOB"
2 ( "ID" NUMBER,
3 "CLOB_VALUE" CLOB,
4 "RANDOM_STRING" VARCHAR2(100)
5 ) SEGMENT CREATION IMMEDIATE
6 PCTFREE 10 PCTUSED 40 INITRANS 1 MAXTRANS 255
7 NOCOMPRESS NOLOGGING
8 STORAGE(INITIAL 1048576 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
9 PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1
10 BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT)
11 LOB ("CLOB_VALUE") STORE AS SECUREFILE (
12 ENABLE STORAGE IN ROW CHUNK 16384
13 NOCACHE NOLOGGING NOCOMPRESS KEEP_DUPLICATES
14 STORAGE(INITIAL 1048576 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
15 PCTINCREASE 0
16 BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT))
17 /
Table created.
SQL>
SQL> set timing on
SQL> BEGIN
2 FOR i IN 1..100 LOOP
3 INSERT INTO TMP_TEST_LARGE_ROWS_CLOB
4 (id, clob_value,random_string)
5 select
6 i*rownum id,
7 DBMS_RANDOM.string ('B', 500),
8 DBMS_RANDOM.string('A', 20)
9 from dual
10 CONNECT BY rownum <= 1000 ;
11 COMMIT;
12 END LOOP;
13 END ;
14 /
PL/SQL procedure successfully completed.
Elapsed: 00:00:46.61
SQL> @sessev
EVENT TOTAL_WAITS TOTAL_TIMEOUTS SECS PCT
-------------------------------------------- ----------- -------------- ---------- -------
db file parallel read 1 0 0 00.00%
db file single write 6 0 0 00.00%
latch: cache buffers chains 1 0 0 00.00%
log file sync 6 0 0 00.00%
enq: RO - fast object reuse 3 0 0 00.00%
control file parallel write 21 0 0 00.00%
db file scattered read 2 0 0 00.00%
log file switch (private strand flush incomp 1 0 .01 00.02%
lete)
local write wait 8 0 .01 00.02%
control file sequential read 280 0 .06 00.12%
events in waitclass Other 735 1 .16 00.33%
Disk file operations I/O 17 0 .22 00.45%
acknowledge over PGA limit 28 28 .25 00.51%
db file sequential read 7154 0 .54 01.11%
CPU 47.46 97.43%
</code>