oracle数据库Insert into数据很慢问题解决办法

作者:袖梨 2022-06-29

上周运营商客户的计费库反应其入库程序很慢,应用方通过监控程序发现主要慢在对于几个表的insert操作上。按照我们的通常理解,insert应该是极快的,为什么会很慢呢?而且反应之前挺好的。这有点让我百思不得其解。通过检查event也并没有发现什么奇怪的地方,于是我通过10046 跟踪了应用的入库程序,如下应用方反应比较慢的表的insert操作,确实非常慢,如下所示:

 代码如下 复制代码

INSERT INTO XXXX_EVENT_201605C (ROAMING_NBR,.....,OFFER_INSTANCE_ID4)
VALUES
 (:ROAMING_NBR,.....:OFFER_INSTANCE_ID4)
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse       17      0.00       0.00          0          0          0           0
Execute     18      1.06      27.41       4534        518      33976        4579
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       35      1.06      27.41       4534        518      33976        4579
 
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 102 
 
Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                      4495        0.03         24.02
  gc current grant 2-way                       2301        0.00          0.77
  SQL*Net more data from client                 795        0.00          0.02
  ......
  latch: gcs resource hash                        1        0.00          0.00

我们可以发现,insert了4579条数据,一共花了27.41秒;其中有24.02秒是处于等待的状态。而且等待事件为顺序读.
很明显这通常是索引的读取操作,实际上检查10046 trace 裸文件,发现等待的对象确实是该表上的2个index。
同时我们从上面10046 trace可以看出,该SQL执行之所以很慢,主要是因为存在了大量的物理读,其中4579条数据的insert,
物理读为4534;这说明什么问题呢? 这说明,每插入一条数据大概产生一个物理读,而且都是index block的读取。
很明显,通过将该index cache到keep 池可以解决该问题。 实际上也确实如此,通过cache后,应用反馈程序快了很多。
那么对该问题,这里其实有几个疑问,为什么这里的SQL insert时物理读如此之高? oracle的keep pool对于缓存对象
的清理机制是如何的?
下面我们通过一个简单的实验来进行说明。
首先我们创建2个测试表,并创建好相应的index,如下所示:

 代码如下 复制代码

SQL> conn roger/roger
Connected.
SQL> create table t_insert as select * from sys.dba_objects where 1=1;
 
Table created.
SQL> create index idx_name_t on t_insert(object_name);
 
Index created.
 
SQL> analyze table t_insert compute statistics for all indexed columns;
 
Table analyzed.
 
SQL> select INDEX_NAME,BLEVEL,LEAF_BLOCKS,DISTINCT_KEYS,CLUSTERING_FACTOR,NUM_ROWS from dba_indexes where table_name='T_INSERT';
 
INDEX_NAME        BLEVEL LEAF_BLOCKS DISTINCT_KEYS CLUSTERING_FACTOR   NUM_ROWS
------------- ---------- ----------- ------------- ----------------- ----------
IDX_NAME_T             1         246         29808             24664      49859
 
SQL> show parameter db_keep
 
NAME                                 TYPE        VALUE
------------------------------------ ----------- --------
db_keep_cache_size                   big integer 0
SQL> alter system set db_keep_cache_size=4m;
 
System altered.
 
SQL> create table t_insert2 as select * from sys.dba_objects where 1=1;
 
Table created.
 
SQL> create index idx_name_t2 on t_insert2(object_name);
 
Index created.
SQL> insert into t_insert select * from sys.dba_objects;
 
49862 rows created.
 
SQL> commit;
 
Commit complete.
 
SQL> insert into t_insert2 select * from sys.dba_objects;
 
49862 rows created.
 
SQL> commit;
 
Commit complete.

从前面的信息我们可以看出,object_name上的index其实聚簇因子比较高,说明其数据分布比较离散。
接着我们现在将index都cache 到keep 池中,如下:

 代码如下 复制代码

SQL> alter index idx_name_t storage (buffer_pool keep);
 
Index altered.
 
SQL> alter index idx_name_t2 storage (buffer_pool keep);
 
Index altered.
SQL> alter system flush buffer_cache;
 
System altered.

这里需要注意的是,仅仅执行alter 命令是不够的,我们还需要手工将index block读取到keep池中,如下:

 代码如下 复制代码

SQL> conn /as sysdba
Connected.
SQL> @get_keep_pool_obj.sql
 
no rows selected
 
SQL> select /*+ index(idx_name_t,t_insert) */ count(object_name) from roger.t_insert;
 
COUNT(OBJECT_NAME)
------------------
             99721
 
SQL> @get_keep_pool_obj.sql
 
SUBCACHE     OBJECT_NAME                        BLOCKS
------------ ------------------------------ ----------
KEEP         IDX_NAME_T                            499
DEFAULT      T_INSERT                              431
 
SQL> select /*+ index(idx_name_t2,t_insert2) */ count(object_name) from roger.t_insert2;
 
COUNT(OBJECT_NAME)
------------------
             99723
 
SQL> @get_keep_pool_obj.sql
 
SUBCACHE     OBJECT_NAME                        BLOCKS
------------ ------------------------------ ----------
KEEP         IDX_NAME_T                             40
KEEP         IDX_NAME_T2                           459
DEFAULT      T_INSERT2                             522
DEFAULT      T_INSERT                              431
 
SQL> select /*+ index(idx_name_t,t_insert) */ count(object_name) from roger.t_insert;
 
COUNT(OBJECT_NAME)
------------------
             99721
 
SQL> @get_keep_pool_obj.sql
 
SUBCACHE     OBJECT_NAME                        BLOCKS
------------ ------------------------------ ----------
KEEP         IDX_NAME_T                            467
KEEP         IDX_NAME_T2                            32
DEFAULT      T_INSERT2                             522
DEFAULT      T_INSERT                              431
 
SQL>

我们可以大致看出,db keep pool 也是存在LRU的,而且对于block的清除机制是先进先出原则。那么为什么前面的问题中,insert会突然变慢呢?

下面我们来进行3次insert 测试。

 代码如下 复制代码

#### one

SQL> select /*+ index_ffs(idx_name_t,t_insert) */ count(object_name) from roger.t_insert;
 
COUNT(OBJECT_NAME)
------------------
            149583
 
SQL> @get_keep_pool_obj.sql
 
SUBCACHE     OBJECT_NAME                        BLOCKS
------------ ------------------------------ ----------
DEFAULT      SQLPLUS_PRODUCT_PROFILE                 1
DEFAULT      RLM$SCHACTIONORDER                      1
DEFAULT      RLM$JOINQKEY                            1
KEEP         IDX_NAME_T                            499
DEFAULT      T_INSERT2                            2113
DEFAULT      T_INSERT                             2113
 
6 rows selected.
SQL> oradebug setmypid
Statement processed.
SQL> oradebug event 10046 trace name context forever,level 12
Statement processed.
SQL> set timing on
SQL> insert into roger.t_insert select * from sys.dba_objects;
 
49862 rows created.
 
Elapsed: 00:00:03.28
SQL> commit;
 
Commit complete.
 
Elapsed: 00:00:00.00
SQL> oradebug tracefile_name
/home/oracle/admin/test/udump/test_ora_11661.trc
 
++++10046 trace
 
insert into roger.t_insert select * from sys.dba_objects
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.01          0          0          0           0
Execute      1      0.95       3.07       3289      11592      96374       49862
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.96       3.08       3289      11592      96374       49862
.....
 
Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                      3168        0.00          0.50
  db file scattered read                          1        0.00          0.00
#### two


SQL> oradebug setmypid
Statement processed.
SQL> oradebug event 10046 trace name context forever,level 12
Statement processed.
SQL> oradebug tracefile_name
/home/oracle/admin/test/udump/test_ora_13163.trc
SQL> set timing on
SQL> insert into roger.t_insert select * from sys.dba_objects;
 
49825 rows created.
 
++++10046 trace
 
insert into roger.t_insert select * from sys.dba_objects
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.01          0          0          0           0
Execute      1      0.87       3.10       3817       8134      87352       49825
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.88       3.11       3817       8134      87352       49825
.....
 
Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                      3827        0.00          0.56
#### three

 


SQL> oradebug setmypid
Statement processed.
SQL> oradebug event 10046 trace name context forever,level 12
Statement processed.
SQL> set timing on
SQL> insert into roger.t_insert select * from sys.dba_objects;
 
49825 rows created.
 
Elapsed: 00:00:03.94
SQL> commit;
 
Commit complete.
 
Elapsed: 00:00:00.01
SQL> oradebug tracefile_name
/home/oracle/admin/test/udump/test_ora_13286.trc
SQL> select /*+ index_ffs(idx_name_t,t_insert) */ count(object_name) from roger.t_insert;
 
COUNT(OBJECT_NAME)
------------------
            249233
 
SQL> @get_keep_pool_obj.sql
 
SUBCACHE     OBJECT_NAME                        BLOCKS
------------ ------------------------------ ----------
DEFAULT      SQLPLUS_PRODUCT_PROFILE                 1
......
DEFAULT      RLM$JOINQKEY                            1
KEEP         IDX_NAME_T                            499
 
++++10046 trace
insert into roger.t_insert select * from sys.dba_objects
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      1.60       3.84       7598      13208     104820       49825
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      1.60       3.84       7598      13208     104820       49825
.....
 
Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                      7618        0.00          1.07
  free buffer waits                             224        0.02          1.30

从测试来看,随着表的数据越来越大,insert的效率会越来越低,也其实主要在于index的问题。
我们可以发现,3次测试过程中,物理读越来越大,而且db file sequential read的等待时间分别从0.5秒,增加到0.56秒,最后增加到1.07秒。 为什么会出现这样的情况呢?
随着表数据的日益增加,导致表上的index也不断增大,同时index的离散度比较高,这样就导致每次insert时,oracle在进行index block读取时,可能在buffer cache中都无法命中相应的block;这样就会导致每次读取需要的index block时,可能都要进行物理读,这势必会导致性能问题的出现。
同时默认的default buffer cache pool虽然也可以缓存index 块,但是也要同时缓存其他的数据块,这样很容易导致

相关的index block被从buffer cache pool中移走。所以这也是前面为什么需要将index cache到keep 池的原因。

相关文章

精彩推荐