db file sequential read

事情是这样的，客户有一套核心的10g业务数据库，需要针对个别大表删除2年前的归档数据，这些表都是普通的堆表(heap table)，没有使用分区或其他技术。因为考虑到不能影响在线业务，所以不能使用insert append/rename的方式来加速删除，只能老老实实地在匿名PL/SQL块里通过rowid批量删除数据，虽然慢一些但还是能接受的,具体的PL/SQL块如下:

DECLARE
   CURSOR table_name_cur IS SELECT /*+ FULL(a) */ a.rowid from table_name a  where time_column<required_date
   table_name_rec table_name_cur%ROWTYPE;
   row_number number;
BEGIN
   row_number :=0;
   OPEN table_name_cur;
   LOOP
      FETCH table_name_cur INTO table_name_rec;
      IF table_name_cur%NOTFOUND
      THEN
      commit;
         EXIT;
      END IF;
      delete from table_name WHERE rowid = table_name_rec.rowid;
      row_number := row_number + 1;
           if (mod (row_number,1000) =0) then
           insert into delete_rows values (row_number);
           commit;
           end if;
   END LOOP;
  insert into delete_rows values (row_number);
   commit;
   CLOSE table_name_cur;
END;
/

可以看到以上使用一个游标FULL SCAN目标数据表取出所需删除行的rowid，之后在循环中不断fetch出rowid并实际删除数据。

问题出在一张不是非常大的LG表上(不超过10GB)，删除这张LG表消耗的时间超过10个小时，而其他更大的表删除也仅用2-3个小时。

针对这一反常现象，客户对删除操作做了10046 level8的跟踪，因为整个删除过程比较长，所以仅 trace了一小段时间，因为这个trace并不完整所以没有办法使用tkprof工具分析该trace。没办法，就分析裸trace信息吧。

从trace内容来看，该时段内主要的等待是db file sequence read(简称DFSR)即数据文件单块读事件，一开始以为是表上有链式行/迁移行造成了大量的DFSR，但客户日常有对该表执行chained rows analyze，没有发现该表上有明显的chained/migrated rows问题。

具体观察该DFSR事件的p1/p2 obj#参数发现这些数据文件单块读主要是针对该LG表的2个索引的，而且最为奇怪的是其中一个索引单块读的频率远多于另外一个索引，比例大约为60:1。这2个索引的差异表现，让我意识到得问题的所在，查看dba_indexes索引视图发现最近一次分析是在4/18日，而2个索引统计信息间最大的差异不在于索引大小，而在于clustering_factor也就是我们说的聚集因子， LG表上大约有6000万条数据，索引A的clustering_factor为170万，而索引B的clustering_factor达到了3400万，即2个索引的聚集因子差20倍，显然这时因为索引A上column更为有序(可能是sequence)而索引B上的字段较为随机造成了这种反差。

因为一开始使用FULL SCAN目标数据表来获取所需的ROWID，所以在实际删除前相关数据行所在的表数据块已经被FULL SCAN读取到buffer cache中了，FULL SCAN使用scattered read多块读，在这里不是主要的性能瓶颈。最主要的问题在于，假设一个table data block中有20行数据，对于clustering_factor较低的索引A而言可能这20行数据都映射到索引的一个leaf block中，而对于clustering_factor很高的索引B而言可能这20行数据需要映射到20个leaf block中，那么如果我们要删除这个数据块中的20行数据，就需要访问索引A上的1个leaf块和索引B上的20个leaf块，因为这些都是历史归档数据，所以日常已经没有业务访问这些old leaf block了，所以这部分的叶子块几乎不会在buffer cache中，服务进程需要把它们”一一”(这里真的是一一，一次读一块)从disk上读取到缓存中；最糟糕的还不止于此，因为实例的buffer cache有限，索引B上的leaf block在读入后可能很快被踢出buffer cache，而因为table与索引B间数据的无序性，这些leaf block可能需要在后续的删除中再次访问，这将对索引B的物理读取代价大大放大了。这种代价反映在Oracle wait interface上就是用户频繁地看到针对某个索引的”db file sequential read”等待事件。

我们通过还原现场，来深入了解一下clustering factor对于删除的影响:

首先要构建一张有一列极端有序，而一列极端无序的数据表

SQL> select * from v$version;

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

SQL> create table sample nologging tablespace users as select rownum t1  from dual  connect by level<=900000; 

Table created. 

SQL> alter table sample add t2 number;
Table altered.

SQL> update sample set t2=dbms_random.value(1,999999999999999);
900000 rows updated.

SQL> commit;
Commit complete.

SQL> create index ind_t1 on sample(t1) nologging;
Index created.

SQL> create index ind_t2 on sample(t2) nologging;
Index created.

SQL> exec dbms_stats.gather_table_stats('MACLEAN','SAMPLE',cascade=>TRUE);
PL/SQL procedure successfully completed.

SQL> select blocks,NUM_ROWS from dba_tables where table_name='SAMPLE';

    BLOCKS   NUM_ROWS
---------- ----------
     13213     900000

SQL> select CLUSTERING_FACTOR,LEAF_BLOCKS,DISTINCT_KEYS,index_name from dba_indexes where table_name='SAMPLE';

CLUSTERING_FACTOR LEAF_BLOCKS DISTINCT_KEYS INDEX_NAME
----------------- ----------- ------------- ------------------------------
           899782        4148        896896 IND_T2
            14975        2004        900000 IND_T1

/* 以上构建了一张90万行的数据表，共13213个block
    T1列通过序列产生，较为有序
    T2列通过随机数产生，无序
    ind_t1索引构建在t1列上，clustering_factor较低14975，接近表上数据块的总数
    ind_t2索引构建在t2列上，clustering_factor为899782，接近表上数据行的总数
*/  

SQL> alter session set events '10046 trace name context forever,level 8';
Session altered.

SQL> set timing on;

DECLARE
   CURSOR table_name_cur IS SELECT /*+ FULL(a) */ a.rowid from sample a  where t1<=900000;
   table_name_rec table_name_cur%ROWTYPE;
   row_number number;
BEGIN
   row_number :=0;
   OPEN table_name_cur;
   LOOP
      FETCH table_name_cur INTO table_name_rec;
      IF table_name_cur%NOTFOUND
      THEN
      commit;
         EXIT;
      END IF;
      delete from sample WHERE rowid = table_name_rec.rowid;
      row_number := row_number + 1;
           if (mod (row_number,1000) =0) then
           insert into delete_rows values (row_number);
           commit;
           end if;
   END LOOP;
  insert into delete_rows values (row_number);
   commit;
   CLOSE table_name_cur;
END;
/

Elapsed: 00:03:28.52 

观察其trace文件，可以发现在多次EXEC/FETCH后就会紧跟一个db file sequential read等待事件 

众所周知db file sequential read等待事件在如v$session/V$session/v$active_session_history
等动态性能视图中的p1代表file号，p2为block号，p3为读取block总数，一般为1
而在10046 trace中可以直接看到file#,block#,blocks和obj#，为了分辨单块读的对象，可以直接从obj#了解

SQL> select object_id,object_name,object_type from dba_objects where object_name in ('SAMPLE','IND_T1','IND_T2');

 OBJECT_ID OBJECT_NAME          OBJECT_TYPE
---------- -------------------- -------------------
   1307548 IND_T1               INDEX
   1307549 IND_T2               INDEX
   1307547 SAMPLE               TABLE

WAIT #3: nam='db file sequential read' ela= 283 file#=6 block#=3311 blocks=1 obj#=1307549 tim=1275797217728516
EXEC #3:c=999,e=349,p=1,cr=2,cu=8,mis=0,r=1,dep=1,og=1,tim=1275797217728552
FETCH #2:c=0,e=5,p=0,cr=1,cu=0,mis=0,r=1,dep=1,og=1,tim=1275797217728578
EXEC #3:c=0,e=49,p=0,cr=1,cu=8,mis=0,r=1,dep=1,og=1,tim=1275797217728641
FETCH #2:c=0,e=4,p=0,cr=1,cu=0,mis=0,r=1,dep=1,og=1,tim=1275797217728663
EXEC #3:c=0,e=36,p=0,cr=1,cu=8,mis=0,r=1,dep=1,og=1,tim=1275797217728712
FETCH #2:c=0,e=3,p=0,cr=1,cu=0,mis=0,r=1,dep=1,og=1,tim=1275797217728732
WAIT #3: nam='db file sequential read' ela= 205 file#=6 block#=3956 blocks=1 obj#=1307549 tim=1275797217728979
EXEC #3:c=0,e=265,p=1,cr=1,cu=8,mis=0,r=1,dep=1,og=1,tim=1275797217729010
FETCH #2:c=0,e=5,p=0,cr=1,cu=0,mis=0,r=1,dep=1,og=1,tim=1275797217729036

[oracle@rh2 udump]$ cat g10r2_ora_5190.trc|grep "db file sequential read"|wc -l
72395

[oracle@rh2 udump]$ cat g10r2_ora_5190.trc|grep "db file sequential read"|grep 1307549|wc -l
67721

[oracle@rh2 udump]$ cat g10r2_ora_5190.trc|grep "db file sequential read"|grep 1307548|wc -l
3878

/* 以上object_id 1307549对应为较高clustering_factor的索引IND_T2，
    该索引发生了绝大多数db file sequential read等待
    而object_id 1307548对应为较低clustering_factor的索引IND_T1,
    该索引发生了较少量的db file sequential read等待
*/

SQL> select sql_id,executions,disk_reads,user_io_wait_time/1000000,elapsed_time/1000000
  2  from v$sql
  3  where sql_text='DELETE FROM SAMPLE WHERE ROWID = :B1 ';

SQL_ID        EXECUTIONS DISK_READS USER_IO_WAIT_TIME/1000000 ELAPSED_TIME/1000000
------------- ---------- ---------- ------------------------- --------------------
31m4m2drt2t5m     900000      74936                 67.862581           147.743482

[oracle@rh2 udump]$ tkprof g10r2_ora_5190.trc 5190.tkf sys=no

DELETE FROM SAMPLE
WHERE
 ROWID = :B1

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute 900000     78.67     147.73      74936     916440    6401613      900000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   900001     78.67     147.73      74936     916440    6401613      900000

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

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1       21.99         21.99
  db file sequential read                     72362        0.05         67.60
  db file scattered read                        543        0.00          0.25
  log file switch completion                     29        0.97          5.81
  free buffer waits                             268        0.01          2.83
  latch: cache buffers lru chain                  3        0.00          0.00
  latch: object queue header operation            5        0.00          0.00
  log file switch (checkpoint incomplete)        22        0.97          8.46
  latch: In memory undo latch                     2        0.00          0.00
  latch: cache buffers chains                     1        0.00          0.00

可能是受限于固化的思维，在我的潜意识中总是觉得clustering_factor聚集因子只会影响select查询语句，而忽略了其对update/delete操作的影响；事实是clustering_factor(注意它只是一个统计信息指标，而非参数)反映了数据在表中的随机分布程度，当表上的数据分布无序时表和索引间的交叉访问将显得很糟糕，这种交叉访问并不局限于查询语句(一个典型可能是INDEX RANGE SCAN-TABLE ACCESS BY INDEX ROWID)，也可能发生在DML操作所隐含的维护索引操作中。

显然除了通过以某些列的顺序整理表外没有太好的方法来降低clustering_factor，但实际上这样做是不可能的。首先定期有序化整理的成本过高了，其次如果表上有多个单列上的不同索引，如我们上述演示中的t1、t2列，如果以t2列的顺序整理表那么一个很可能的结果是t1列上的索引的clustering factor猛增，如:

SQL> create table ordered_sample nologging tablespace users as select * From sample order by t2;
Table created.

SQL> truncate table sample;
Table truncated.

SQL> insert /*+ append */ into sample select * from ordered_sample;
900000 rows created.

SQL> commit;
Commit complete.

SQL> exec dbms_stats.gather_table_stats('MACLEAN','SAMPLE',cascade=>TRUE);
PL/SQL procedure successfully completed.

SQL> select clustering_factor,index_name from dba_indexes where table_name='SAMPLE';

CLUSTERING_FACTOR INDEX_NAME
----------------- ------------------------------
           899782 IND_T1
             3983 IND_T2

/* 可以看到ind_t2所以的clustering_factor的确下降了，换得的是ind_t1对应的增长 */

针对由该clustering_factor引起的低效率批量delete/update操作，我们可以通过以下措施减少”db file sequential read”等待的出现:

通过keep cache保留池等技术将clustering_factor过高的索引缓存住，以避免频繁地单块物理读，从而提高性能
如果你正在执行一个大作业，那么可以暂时将clustering_factor过高的索引drop掉，在完成操作后再重建该索引，这样起到加速作业的目的

rebuild重建索引在以上案例的情景中获益并不大。

另外”db file sequential read”单块读等待是一种最为常见的物理IO等待事件，这里的sequential指的是将数据块读入到相连的内存空间中(contiguous memory space)，而不是指所读取的数据块是连续的。该wait event可能在以下情景中发生:

最为常见的是执行计划中包含了INDEX FULL SCAN/UNIQUE SCAN,此时出现”db file sequential read”等待是预料之中的，一般不需要我们去特别关注
当执行计划包含了INDEX RANGE SCAN-(“TABLE ACCESS BY INDEX ROWID”/”DELETE”/”UPDATE”)，服务进程将按照”访问索引->找到rowid->访问rowid指定的表数据块并执行必要的操作”顺序访问index和table，每次物理读取都会进入”db file sequential read”等待，且每次读取的都是一个数据块；这种情况下clustering_factor将发挥其作用，需要我们特别去关注，本例中提及的解决方法对这种情景也有效
Extent boundary,假设一个Extent区间中有33个数据块，而一次”db file scattered read”多块读所读取的块数为8，那么在读取这个区间时经过4次多块读取后，还剩下一个数据块，但是请记住多块读scattered read是不能跨越一个区间的(span an extent)，此时就会单块读取并出现”db file scattered read”。这是一种正常现象，一般不需要额外关注
假设某个区间内有8个数据块，它们可以是块a,b,c,d,e,f,g,h，恰好当前系统中除了d块外的其他数据块都已经被缓存在buffer cache中了，而这时候恰好要访问这个区间中的数据，那么此时就会单块读取d这个数据块，并出现”db file sequential read”等待。注意这种情况不仅于表，也可能发生在索引上。这是一种正常现象，一般不需要额外关注
chained/migrated rows即链式或迁移行，这里我们不介绍链式行的形成原因，chained/migrated rows会造成服务进程在fetch一行记录时需要额外地单块读取，从而出现”db file sequential read”。这种现象需要我们特别去关注，因为大量的链式/迁移行将导致如FULL SCAN等操作极度恶化(以往的经验是一张本来全表扫描只需要30分钟的表，在出现大量链式行后，全表扫描需要数个小时)，同时也会对其他操作造成不那么明显的性能影响。可以通过监控v$sysstat视图中的”table fetch continued row”操作统计来了解系统中链式/迁移行访问的情况，还可以通过DBA_TBALES视图中的CHAIN_CNT来了解表上的链式/迁移行情况，当然这要求定期收集表上的统计信息；如果没有定期收集的习惯，那么可以配合@?/rdbms/admin/utlchain脚本和analyze table list chained rows 命令来获取必要的链式行信息
创建Index entry，显然当对表上执行INSERT操作插入数据时，虽然在执行计划中你看不到过多的细节，但实际上我们需要利用索引来快速验证表上的某些约束是否合理，还需要在索引的叶子块中插入相关的记录，此时也可能出现”db file sequential read”等待事件，当然这还和具体的插入的方式有关系。这是一种正常现象，一般不需要额外关注
针对表上的UPDATE/DELETE，不同于之前提到的”INDEX RANGE SCAN-UPDATE/DELETE”，如果我们使用rowid去更新或删除数据时，服务进程会先访问rowid指向的表块(注意是先访问table block)上的行数据，之后会根据该行上的具体数据去访问索引叶子块(注意Oracle并不知道这些leaf block在哪里，所以这里同样要如range-scan/unique-scan那样去访问index branch block)，这些访问都将会是单块读取，并会出现’db file sequential read’，完成必要的读取后才会执行更新或删除的实际EXEC操作，如下例:

以下trace中，obj#=1307547为sample表，而obj#=1307549为sample表上的唯一一个索引 

PARSING IN CURSOR #10 len=58 dep=0 uid=64 oct=6 lid=64 tim=1275805024007795 hv=505118268 ad='d387e470'
update sample set t2=t2+1 where rowid='AAE/OzAAEAAANUEAAQ'
END OF STMT
PARSE #10:c=1999,e=3016,p=1,cr=1,cu=0,mis=1,r=0,dep=0,og=1,tim=1275805024007787
WAIT #10: nam='db file sequential read' ela= 314 file#=4 block#=54532 blocks=1 obj#=1307547 tim=1275805024008308
WAIT #10: nam='db file sequential read' ela= 206 file#=6 block#=20 blocks=1 obj#=1307549 tim=1275805024009235
WAIT #10: nam='db file sequential read' ela= 206 file#=6 block#=742 blocks=1 obj#=1307549 tim=1275805024009496
WAIT #10: nam='db file sequential read' ela= 207 file#=6 block#=24 blocks=1 obj#=1307549 tim=1275805024009750
EXEC #10:c=2000,e=2297,p=6,cr=2,cu=8,mis=0,r=1,dep=0,og=1,tim=1275805024010210   --实际的UPDATE发生在这里

当大量执行这类UPDATE/DELETE操作时将需要频繁地交叉访问表和索引，如果恰好表上的某个索引有较高的clustering_factor的话，那么就会形成本例中的这种性能问题了。实际上当表上有较多索引时，使用rowid来批量update/delete数据这种方式是不被推荐的，仅当表上没有索引时才可能十分高效。如果你坚持要这样做，那么可以参照上面提到的建议。

8.BUG!BUG!已知在9i RAC及10g中使用ASM的情况下，存在引发在适用情况下不使用”scattered read”多块读而去使用”sequential read”的BUG。如果你的问题和上述情景都不匹配，但又有大量的”db file sequential read”等待事件，那么你有可能遇到bug了。在这里列出部分已知bug:

Bug#	Version Affected
Bug 7243560 – High “db file sequential read” IO times when using ASM	10.2.0.4/11.1.0.7
Bug 7243560: RAPID INCREASE IN DB FILE SEQUENTIAL READ AFTER MOVING TO ASM	10.2.0.3
Bug 9711810: EXCESSIVE DB FILE SEQUENTIAL READS WITH NON COMPLIANT BUFFER CACHE ON RAC	9.2.0.8
Bug 9276739: INSERT STATEMENT HAS SLOW PERFORMANCE WITH DB FILE SEQUENTIAL READ	10.2.0.4
Bug 8625100: EXCESSIVE DB FILE SEQUENTIAL READ ON UNDO	10.2.0.4
Bug 8669544: HIGH DB FILE SEQUENTIAL READ AND GC CR DISK READ WAIT EVENTS DURING FULL SCAN	10.2.0.4
Bug 7427133: AN INSERT CAUSES LOTS OF ‘DB FILE SEQUENTIAL READ’ WAITS FOR THE INDEX BLOCKS	9.2.0.8
Bug 8493139: INCREASE IN DB FILE SEQUENTIAL READ WAITEVENT AFTER MIGRATING TO 10 RAC/ASM	10.2.0.4
Bug 5882268: PERFORMANCE ISSUE WITH ‘DB FILE SEQUENTIAL READ’	10.2.0.2
Bug 7415702: LOTS OF ‘DB FILE SEQUENTIAL READ’ ON UNDO	10.2.0.3
Bug 5607724: 10202 DB FILE SEQUENTIAL READ THRICE AFTER UPGRADE FROM 9I	10.2.0.2

何时会发生db file sequential read等待事件？

SQL调优:Clustering Factor影响数据删除速度一例