概述

在客户现场，由于压测的需要，客户开发人员写了一个简单的存储过程导入测试数据，它的逻辑很简单，对1000个人构造结构相同的批量数据插入到多个表中，一个人的数据插入对应多个insert into和一次commit，1000人就是这样的过程执行1000次。存储过程有一个参数控制对每个人构造多少个操作记录，实际执行时都是写死为2000，所以一次存储过程的调用相当于会构造200万的操作记录，其中一次commit会提交2000条操作记录。

问题

在导入的过程中发现一个问题，随着表的数据量越来越多，存储过程的调用耗时会越来越大，导入速率越来越低，例如表在没有数据的情况下，导入速率在3~4万/分钟，但是表数据量在2000万级别时，导入速率下降到不足1万/分钟。
从这个现象看第一反应是索引维护代价导致的，因为表数据量越大维护代价就越大，并且每个insert表都会有多个索引，但是这个问题的不正常的地方在于代价随着数据量会越来越大，维护代价增长太大了，超过了正常的认知。

问题复现

为了分析此问题的原因，我将现场的场景进行了简化，使用了一个简单的模型来模拟此问题：
表结构：

CREATE TABLE "TEST_SCHEMA"."TEST_INSERT_TABLE"
(
"ID" VARCHAR(64) NOT NULL,
"NAME" VARCHAR(64),
NOT CLUSTER PRIMARY KEY("ID")) STORAGE(ON "MAIN", CLUSTERBTR) ;

CREATE TABLE "TEST_SCHEMA"."TEST_INSERT_TABLE_2"
(
"ID" VARCHAR(64) NOT NULL,
"NAME" VARCHAR(64),
NOT CLUSTER PRIMARY KEY("ID")) STORAGE(ON "MAIN", CLUSTERBTR) ;

存储过程：

CREATE OR REPLACE PROCEDURE TEST_SCHEMA.TEST_INSERT_PROC (BATCH_NUM IN INT, INSERT_COUNT IN INT)
AS
    v_i INT;
    v_ii INT;
    v_start_time TIMESTAMP;
    v_end_time TIMESTAMP;
    v_insert_consume INT;
    v_commit_consume INT;
    v_tmp_start TIMESTAMP;
    v_tmp_end TIMESTAMP;
BEGIN
    v_insert_consume := 0;
    v_commit_consume := 0;
    v_start_time := SYSTIMESTAMP;
    DBMS_OUTPUT.PUT_LINE('    v_start_time:' || v_start_time);
    v_i := 0;
    WHILE v_i < BATCH_NUM LOOP
        v_ii := 0;
        WHILE v_ii < INSERT_COUNT LOOP
        	v_ii := v_ii + 1;
        	v_tmp_start := SYSTIMESTAMP;
	    	insert into TEST_SCHEMA.test_insert_table(id,name) values(newid(),'abc');
        	v_tmp_end := SYSTIMESTAMP;
	    	v_insert_consume := v_insert_consume + TIMESTAMPDIFF(us,v_tmp_start,v_tmp_end);
        END LOOP;
	   	v_tmp_start := SYSTIMESTAMP;
        commit;
 		v_tmp_end := SYSTIMESTAMP;
    	v_commit_consume := v_commit_consume + TIMESTAMPDIFF(us,v_tmp_start,v_tmp_end);
    	v_i := v_i + 1;
    END LOOP;
    v_end_time := SYSTIMESTAMP;
    DBMS_OUTPUT.PUT_LINE('      v_end_time:' || v_end_time);
    DBMS_OUTPUT.PUT_LINE('         consume:' || TIMESTAMPDIFF(ms,v_start_time,v_end_time) || ' ms');    
    DBMS_OUTPUT.PUT_LINE('v_insert_consume:' || v_insert_consume || ' us, avg:' || v_insert_consume/(BATCH_NUM*INSERT_COUNT) || ' us');
    DBMS_OUTPUT.PUT_LINE('v_commit_consume:' || v_commit_consume || ' us, avg:' || v_commit_consume/BATCH_NUM || ' us');
EXCEPTION
    WHEN OTHERS THEN
        ROLLBACK;
        DBMS_OUTPUT.PUT_LINE('error: ' || SQLCODE || ' - ' || SQLERRM);
        RAISE;
END;

CREATE OR REPLACE PROCEDURE TEST_SCHEMA.TEST_INSERT_PROC_2 (BATCH_NUM IN INT, INSERT_COUNT IN INT)
AS
    v_i INT;
    v_ii INT;
    v_start_time TIMESTAMP;
    v_end_time TIMESTAMP;
    v_insert_consume INT;
    v_commit_consume INT;
    v_tmp_start TIMESTAMP;
    v_tmp_end TIMESTAMP;
BEGIN
    v_insert_consume := 0;
    v_commit_consume := 0;
    v_start_time := SYSTIMESTAMP;
    DBMS_OUTPUT.PUT_LINE('    v_start_time:' || v_start_time);
    v_i := 0;
    WHILE v_i < BATCH_NUM LOOP
        v_ii := 0;
        WHILE v_ii < INSERT_COUNT LOOP
        	v_ii := v_ii + 1;
        	v_tmp_start := SYSTIMESTAMP;
	    	insert into TEST_SCHEMA.test_insert_table_2(id,name) values(newid(),'abc');
        	v_tmp_end := SYSTIMESTAMP;
	    	v_insert_consume := v_insert_consume + TIMESTAMPDIFF(us,v_tmp_start,v_tmp_end);
        END LOOP;
	   	v_tmp_start := SYSTIMESTAMP;
        commit;
 		v_tmp_end := SYSTIMESTAMP;
    	v_commit_consume := v_commit_consume + TIMESTAMPDIFF(us,v_tmp_start,v_tmp_end);
    	v_i := v_i + 1;
    END LOOP;
    v_end_time := SYSTIMESTAMP;
    DBMS_OUTPUT.PUT_LINE('      v_end_time:' || v_end_time);
    DBMS_OUTPUT.PUT_LINE('         consume:' || TIMESTAMPDIFF(ms,v_start_time,v_end_time) || ' ms');    
    DBMS_OUTPUT.PUT_LINE('v_insert_consume:' || v_insert_consume || ' us, avg:' || v_insert_consume/(BATCH_NUM*INSERT_COUNT) || ' us');
    DBMS_OUTPUT.PUT_LINE('v_commit_consume:' || v_commit_consume || ' us, avg:' || v_commit_consume/BATCH_NUM || ' us');
EXCEPTION
    WHEN OTHERS THEN
        ROLLBACK;
        DBMS_OUTPUT.PUT_LINE('error: ' || SQLCODE || ' - ' || SQLERRM);
        RAISE;
END;

“TEST_SCHEMA”.“TEST_INSERT_TABLE"表只有一个非聚集的主键索引，其中会预先导入3000万条数据，TEST_SCHEMA.TEST_INSERT_PROC(BATCH_NUM IN INT, INSERT_COUNT IN INT)这个存储过程会在执行BATCH_NUM次commit操作，每次commit之前会向"TEST_SCHEMA”."TEST_INSERT_TABLE"中执行INSERT_COUNT次insert操作。

作为对比测试，“TEST_SCHEMA”.“TEST_INSERT_TABLE_2"和TEST_SCHEMA.TEST_INSERT_PROC_2(BATCH_NUM IN INT, INSERT_COUNT IN INT)的逻辑完全一样，但是插入的表对象是"TEST_SCHEMA”.“TEST_INSERT_TABLE_2”。

在经过多次测试发现，TEST_SCHEMA.TEST_INSERT_PROC(1000, 500)的平均耗时在

测试结果显示，3000万数据表相比空表，insert语句耗时增长接近一倍，commit语句耗时接近5倍。从磁盘负载来看，3000万级别的表进行insert和commit测试时，使用率一直接近100%。

尝试调过以下参数：

INDEX_FINS_FLAG=511
BTR_SPLIT_MODE=1
COMMIT_BATCH=100
COMMIT_BATCH_TIMEOUT=100

但是调整前后效果都一样，3000万级别的insert和commit还是一样很慢。

然后再将COMMIT_WRITE调整为IMMEDIATE,NOWAIT后，两种场景下的insert耗时比例没有变化，但是commit耗时比例接近1：1了，说明commit耗时增长接近5倍的原因在于将REDO LOG刷盘，在3000万级别时执行commit时，表的REDO LOG刷盘会增长5倍的大小（不一定是5倍的REDO LOG大小）。

总结

此问题的原因在于索引维护代价，基表的数据量越多，在commit刷盘时会导致5倍的刷盘量，这种异常情况还需要进一步分析，找到这多出来的几倍刷盘量的来源。