问题描述
上周运营商客户的计费库反应其入库程序很慢,应用方通过监控程序发现主要慢在对于几个表的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 池的原因。
「喜欢这篇文章，您的关注和赞赏是给作者最好的鼓励」
关注作者
【版权声明】本文为墨天轮用户原创内容，转载时必须标注文章的来源（墨天轮），文章链接，文章作者等基本信息，否则作者和墨天轮有权追究责任。如果您发现墨天轮中有涉嫌抄袭或者侵权的内容，欢迎发送邮件至：contact@modb.pro进行举报，并提供相关证据，一经查实，墨天轮将立刻删除相关内容。
