0
点赞
收藏
分享

微信扫一扫

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂

如何优化索引分裂

索引分裂由于其特殊性,分裂行为是无法避免的,更多的优化方案是减少分裂,或降低索引分裂对数据库整体性能的影响。当然还有设置较小的block_size或创建反向索引等优化方案,还需要具体问题具体分析。
以下几种是的优化索引分裂的常用手段。

1 分区索引

大量的索引分裂的优化场景是采用索引分区来解决,特别是HASH索引可以有效的降低分裂块的争用,其原理就是通过HASH分散争用块,可以并发操作索引叶子节点,降低单个index block上的并发,继而降低索引分裂带来的性能抖动。

2 参数调整

在日常的数据库运维工作中经常会遇到偶发性的INSERT导致索引分裂引发的阻塞问题,分裂会话持续时间较长,分裂行为往往就是慢在空块(free block)寻找上,可以通过动态性能视图v$SYSSTAT中的一些指标来定位索引分裂时间较长的原因是否发生在空块寻找上,对比AWR ”Other Instance Activity Stats”部分中的“failed probes on index block reclamation”指标。

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_索引


图 130

该指标意思是索引分裂在寻找空块时,扫描大量的“可复用的free block”,分裂需要的free block优先会找索引中100% free的索引块,ASSM管理表空间中bitmap管理区分0~25%、25%~50%、50%~75%和75%~100%四种使用率的索引块。寻找“可复用的free block”会把Free Space 75%~100%的索引块都会扫描一遍,从而找到真正100% free的索引块,导致了索引单块读增加,在物理读缓慢的场景下会加剧索引分裂的严重性。

可以设置以下两个参数在一定程度上缓解enq: TX - index contention索引分裂的争用。

参数“_assm_high_gsp_threshold ”和“ _assm_low_gsp_threshold”。

如下是参数的默认值:

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_优化索引分裂_02


图 131

当索引发生分裂时,会寻找free block,以上两个参数就是控制在寻找free block时,当找到free block前reject的次数,当达到_assm_high_gsp_threshold则扩展新块,减小两个隐含参数的值的可以减少free block的检索并积极扩展新块,也就能一定的缓解索引争用对业务的影响。

3 提升分裂效率(减少物理读,减少gc等)

物理读和严重的GC等待也是导致索引分裂较慢的常见因素,可以通过减少物理读或使用IO低延迟的存储,比如为减少物理读,可以设置较大的数据库内存或将索引cache到keep pool中,由于keep pool遵循FIFO先进先出机制,可以减少物理读。
在RAC集群环境下可以通过不同的应用访问不同集群节点,以service的形式将不同的应用或不同的应用功能分开节点访问,比如A应用只访问节点1,B应用只访问节点2,并且将各个应用对应表和索引的统计信息任务放在本地采集,减少GC等待。也就就减少了索引分裂中GC等待的消耗。

4 应用层优化数据结构

在右倾非常严重的索引中,由于数据的特殊性,新插入的数据都是单向递增的,可以考虑从业务层面优化字段数据,比如索引字段数据中加入省份代码、地市代码、商户编号等字符,可以有效缓解索引右倾导致的分裂竞争。往往这一类优化需要开发和业务配合更多,对代码的侵入性较高,改动的阻力也较大,但不排除它仍是一个非常有效的优化手段。

案例分享-索引分裂导致的性能故障

下面通过一个真实的生产环境故障案例来了解下索引分裂,也希望读者可以通过本案例能熟悉常见的故障分析思路。故障分析是一个不断质疑和不断解惑的过程,最终可以通过数据库原理和故障日志或信息来解释故障根因。感谢孙加鹏为此提供的案例。

1 问题概述和故障现象

某金融客户数据库于2021年02月02日早上08:50分左右出现业务响应延迟的现象,数据库监控发现活跃会话(AAS)飙高,高峰飚到300以上。待客户登录数据库时,发现高峰活跃会话已经消逝,数据库表现正常,数据库高负载维持了大约6~7分钟左右,客户及时将故障事件反馈给服务项目经理,因数据库已恢复正常,当时建议客户把数据库的活跃会话信息备份一下,即使用CTAS方式备份了GV$ACTIVE_SESSION_HISTORY视图数据。待后续做详细分析与复盘。

2 ASH活跃会话分析

首先检查ASH(Active Session History)确定故障时间点活跃会话信息,可以看出故障高峰期数据库活跃会话飙升到330左右,时间上可以精确到故障发生时间是从8点55分00秒开始。

select to_char(sample_time,'YYYY-MM-DD HH24:MI:SS'),count(*)
from ash20210202 ash
where ash.sample_time between to_date('2021-02-02 08:50:00', 'yyyy-mm-dd hh24-mi-ss') 
	  and  to_date('2020-02-02 09:10:00', 'yyyy-mm-dd hh24-mi-ss')
group by to_char(sample_time,'YYYY-MM-DD HH24:MI:SS')
order by 2 desc

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_b-tree_03


图 132

在这20分钟的ASH种,对EVENT列做group by分组统计,查看这一段时间内的等待事件分布情况:

select to_char(sample_time,'YYYY-MM-DD HH24:MI:SS'),event,count(*)
from ash20210202 ash
where ash.sample_time between to_date('2021-02-02 08:50:00', 'yyyy-mm-dd hh24-mi-ss') 
	  and  to_date('2020-02-02 09:10:00', 'yyyy-mm-dd hh24-mi-ss')
group by to_char(sample_time,'YYYY-MM-DD HH24:MI:SS')
order by 3 desc

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_索引_04


图 133

从等待时间来看,等待事件都是enq: TX - index contention,也就是索引争用。对这个等待事件官方的解释如下:

Waits for TX in mode 4 also occur when a transaction inserting a row in an index has to wait for the end of an index block split being done by another transaction. This type of TX enqueue wait corresponds to the wait event enq: TX - index contention.

大致意思就是当一个session向一个索引块中执行插入/更新时产生了索引块的split,而其他的session也要往该索引块中插入数据,此时,其他session必须要等待split完成,由此引发了该等待事件,其他session此时的等待时间就是enq: TX - index contention。

继续分析ASH,寻找等待enq: TX - index contention等待事件对应的SQL有哪些?

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_优化索引分裂_05


图 134

从上图可以看出,故障时间段发生索引分裂会话阻塞的SQL都是一致的,这些会话的SQL全部都是bmscrhbvf6hpt这个INSERT SQL,SQL文本如下:

INSERT INTO ENMO_LOG_INFO( ID, MERID, TEMID, LOG_DATE, LOG_TIME, CREATE_DATE, RESV1, RESV2, RESV3, RESV4, BACK_MESSAGE, SEND_MESSAGE, MEMO ) 
VALUES( :1 , :2 , :3 , :4 , :5 , :6 , :7 , :8 , :9 , :10 , :11 , :12 , :13  ) 
RETURNING ROWID INTO :14

在对表ENMO_LOG_INFO进行数据插入时导致的索引分裂争用,可以通过ASH视图中CURRENT_OBJ#列发现分裂的索引对应表上字段RESV1。

select to_char(sample_time,'YYYY-MM-DD HH24:MI:SS'),event,blocking_session,count(*)
from ash20210202 ash
where ash.sample_time between to_date('2021-02-02 08:50:00', 'yyyy-mm-dd hh24-mi-ss') 
  and to_date('2020-02-02 09:10:00', 'yyyy-mm-dd hh24-mi-ss')
  and event='enq: TX - index contention'
group by to_char(sample_time,'YYYY-MM-DD HH24:MI:SS'),event,blocking_session
order by 4 desc

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_索引_06


图 135

继续分析ASH的阻塞关系链,发现所有会话的阻塞源头都来自于session_id=1744这个连接会话,查看1744会话当时具体的执行SQL和等待事件。

Select to_char(sample_time,'YYYY-MM-DD HH24:MI:SS'),event,sql_id,blocking_session,current_obj#
from ash20210202 ash
where ash.sample_time between to_date('2021-02-02 08:50:00', 'yyyy-mm-dd hh24-mi-ss') 
  and to_date('2020-02-02 09:10:00', 'yyyy-mm-dd hh24-mi-ss')
  and session_id=1744
group by to_char(sample_time,'YYYY-MM-DD HH24:MI:SS'),event,blocking_session
order by 1

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_优化索引分裂_07


图 136

SESSION_ID=1744会话从08:55:00开始也在执行SQL_ID=bmscrhbvf6hpt这条INSERT INTO ENMO_LOG_INFO的业务SQL语句。说明会话1744此时正在执行split index操作。

因为自始至终索引分裂的阻塞源头都在session_id=1744的会话上,所以可以抛开时间轴,具体分析1744会话在执行这条INSERT SQL期间具体有哪些等待事件。

select event,count(*)
from ash20210202 ash
where ash.sample_time between to_date('2021-02-02 08:50:00', 'yyyy-mm-dd hh24-mi-ss') 
  and to_date('2020-02-02 09:10:00', 'yyyy-mm-dd hh24-mi-ss')
  and session_id=1744
group by event
order by 2

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_b-tree_08


图 137

通过查询分析ASH可以看出SESSION_ID=1744的会话等待事件以单块读为主,还伴随着一些gc类的等待,单块读的等待和GC等待的对象都是CURRENT_OB#=651943的对象上,该对象就是表ENMO_LOG_INFO上的索引IDX_ENMO_LOG_INFO_NEW_02,因此当时是有索引单块读,但是为何索引单块读会引发其他会话的TX index contention等待,其实通过等待事件分析会话1744当时就是在做索引分裂操作,1744在寻找索引IDX_ENMO_LOG_INFO_NEW_02上的空闲块,也就是free block(100% free),Oracle数据库的索引采用bitmap位图管理,segment bitmap block中只区分0%-25% FREE,25%-50% FREE , 50%-75% FREE, 75%-100% FREE的数据块,但Oracle无法直接区分 75%-100% FREE的数据块中哪些是100% free的数据块,Oracle这样做的目的是为了尽可能的重用索引块,以避免过度分配空间,当oracle发现没有可重用的数据块时才会扩展索引空间并分裂索引块。

我们还可以看一下1744会话的整体阻塞链和等待事件占比,从下图来看,db file sequential read占比最高。但也伴随着GC类的等待。

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_优化索引分裂_09


图 138

会话1744执行一条INSERT操作整体耗时达到了369秒,从8点55分00秒开始一直到9点01分09秒执行完成,耗时较长,在寻找可复用的free block过程中耗时最长,同时遇到全局GC数据块争用,导致split操作变慢,进而导致大量INSERT进程长时间等待enq: TX – index contention。

1744会话的split index操作时间过长主要原因是索引较大,索引逻辑读和物理读较高,并且存在全局的GC索引块争用的问题。我会在后面通过两个小章节分析说明一下会话1744的耗时以及索引分裂为何会产生如此高的物理读。

但在此之前请容我暂停一下此前的故障分析思路,因为在分析日志过程中发现节点2在故障时间段有一例ORA-01555报错,这充分引起了客户和我的关注,客户提出一个疑问,节点2的ORA-01555报错是否也与此次索引分裂有关?是因是果?这一点也是需要得出根因分析的结论。

3 节点2 实例ORA-01555报错分析

除了上述节点1发生索引分裂问题之外,在2月2日凌晨2点58左右,节点2告警日志有ORA-01555快照过旧的报错信息,也非常值得引起关注,从触发快照过旧的SQL来看是统计信息收集的SQL。

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_优化索引分裂_10


图 139

从节点2的ALERT告警日志和JOB进程日志信息分析2:58:54时统计信息收集任务因快照过旧导致部分表统计信息任务失败。

但是ORA-01555 snapshot too old发生的回滚段 number 75却是UNDOTBS1表空间,UNDOTBS1表空间是节点1的默认UNDO表空间。节点2在凌晨2点开始自动开始统计信息收集,窗口时间3小时,在凌晨5点时因窗口时间截止而终止;

select *
from dba_scheduler_job_run_details
where job_name='ORA$AT_OS_OPT_SY_39661';

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_b-tree_11


图 140

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_索引_12


图 141

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_索引_13


图 142

表ENMO_LOG_INFO的统计信息也没有采集完成,在节点2的trace中也可以看出:

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_索引_14


图 143

节点2统计信息任务采集虽然没有采集完成,但这也是导致节点1早上8点55开始索引分裂后会话1744不但有很多单块读还有很多GC类等待事件的原因。

导致节点2统计信息采集的SQL失败并触发ORA-01555的原因是,节点1当时在做表ENMO_LOG_INFO的truncate partition update global index操作,update gloabl index的操作,导致统计信息采集任务的查询SQL会产生大量的一致性读,也就是读UNDOTBS1表空间中的一致性块,直至快照过旧导致统计信息采集的job任务失败,也导致整体统计信息的调度job执行比较缓慢。

Truncate partition的定时任务也因UNDOTBS1无法扩展而失败,从客户创建的procedure的日志表中的时间来看是04点13分57秒报错。

客户环境数据库上有一个自定义的procedure,并通过系统crontab控制在每月2号凌晨两点开始自动执行procedure,procedure会将表ENMO_LOG_INFO上的分区做truncate partition update global index操作,procedure脚本内容如下:

create or replace procedure trun_expired_data(vTableName varchar2, vInterval int)
as
  t_code number(10);
  t_errm varchar2(200);
  t_flag int:=0;
  t_btime varchar2(14):='2200';
  t_etime varchar2(14):='0300';
  vMinPart varchar2(50);
  vSql varchar2(1000);
begin
  select vTableName || '_' || to_char(sysdate-vInterval,'yyyymmdd') into vMinPart from dual;

  for cr in (select *
               from user_tab_partitions a
              where a.table_name = upper(vTableName)
                and a.partition_name < upper(vMinPart)
                and a.partition_name >= vTableName||'_20170101'
                and not exists (select 1
                                  from sc_trun_expired_record b
                                 where b.tablename = upper(vTableName)
                                    and b.partition_name = a.partition_name)
               order by a.partition_name asc)
  loop
    if to_char(sysdate,'hh24mi') between t_etime and t_btime then
      t_flag := 1;
    end if;
    exit when t_flag = 1;

    vSql := 'alter table ' || vTableName || ' truncate partition ' || cr.partition_name || ' update global indexes parallel 4';
    execute immediate vSql;

    insert into sc_trun_expired_record(rtime,tablename,partition_name,error_num,error)
      values(sysdate, vTableName, cr.partition_name, null, null);
    commit;
  end loop;
exception
  when others then
    t_code:=sqlcode;
    t_errm:=sqlerrm;
    rollback;
    insert into sc_trun_expired_record(rtime,tablename,partition_name,error_num,error)
      values(sysdate, vTableName, 'fail', t_code,t_errm);
    commit;
end;
/

从procedure的日志表来看,报错时间是04点13分57秒,报错代码是ORA-30036 UNDOTBS1表空间无法扩展。

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_b-tree_15


图 144

但实际报错时间是凌晨2:54:08左右,从节点1的日志trace oradb1_ora_172310.trc中可以看到具体的报错时间,usn=9的undo segment _SYSSMU9_1424341975$无法扩展。

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_b-tree_16


图 145

查看当时消耗UNDO最多的事务或SQL,查看GV$UNDOSTAT动态性能视图。

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_优化索引分裂_17


图 146

从图146的蓝色箭头所示数据来看,在split操作失败后,undo回滚段也回收了一些空间。

占用UNDO空间最多的是SQL_ID=9kd26uh59n16h这条SQL,SQL文本如图147所示。

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_b-tree_18


图 147

此SQL就是truncate partition update global index的递归SQL。可以参考Oracle官方Mos文档:《Partition Truncate or Drop Taking a Long Time With SQL ‘insert /*+ RELATIONAL . . . delete global indexes’ (Doc ID 2177233.1)》

4 1744会话耗时分析

从ASH中可以看出会话1744是阻塞的源头和根因,1744会话的index split操作耗时约369秒,其中集群等待耗时约84秒,物理读IOPS 121万并且等于disk_reads,说明都是单块读,跟ASH中索引单块读对应。物理读约9.3GB,逻辑读约20.8GB。

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_b-tree_19


图 148

会话1744的索引分裂主要的耗时分为两部分,集群gc等待和索引的单块读。ASH中也可以很明显的看出。

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_索引_20


图 149

db file sequential read对应的bloc等待事件对应P2值都不一样,说明split期间的单块读并没有重复。

select p1,p2,count(*)
from ash20210202 ash
where ash.sample_time between to_date('2021-02-02 08:50:00', 'yyyy-mm-dd hh24-mi-ss') 
  and to_date('2020-02-02 09:10:00', 'yyyy-mm-dd hh24-mi-ss')
  event='db file sequential read'
  and session_id=1744
group by p1,p2
order by 1

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_b-tree_21


图 150

任意dump 几个index block,可以看出当时读的索引块中数据都是202012份的数据。

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_优化索引分裂_22


图 151

并且从index block的创建SCN来看,该索引块应该就是2021年2月2日当天创建的。

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_优化索引分裂_23


图 152

由于编写详细故障复盘报告时故障已经过去一周,因此UNDO中已经查不到SCN对应的时间点,但是从数据库当前最小SCN转换成时间来大体估算下索引块应该就是在2021年2月2日创建,当时凌晨2点之后由于truncate partition更新了索引块(update global index)。

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_b-tree_24


图 153

从1744会话当时采集的SQL Monitor中物理读达到9.3GB来看,表ENMO_LOG_INFO上共有三个分区,索引IDX_ENMO_LOG_INFO_NEW_02的大小约26GB,202012分区对应的索引数据大约占9GB,所以会话1744当时的索引分裂操作是扫描了索引IDX_ENMO_LOG_INFO_NEW_02对应数据在202012分区上的所有索引块。

2月2日凌晨,在truncate partition 202012 … update gloabl index的时候,索引IDX_ENMO_LOG_INFO_NEW_02相当于重建了,12月份的索引数据块都重新分布,索引数据类似做了delete+insert操作。

5 实验测试-索引分裂为何产生高IO

如图154所示,为何一条INSERT SQL的索引分裂会产生如此高的物理读和逻辑读,为何split寻找可用块需要将所有索引块进行扫描?下面通过具体的实验来复现故障并做进一步探索。

Oracle中B-tree索引的访问方法(十二)-- 如何优化索引分裂_索引_25


图 154

在 <1744会话耗时分析> 中我们通过ASH和index dump分析是truncate partition update global index失败导致索引分裂在寻找空闲 block时会扫描delete index(update global index)失败的所有块,也就是202012分区数据对应的索引块。下面通过event 10224来帮助我们定位索引90-10分裂是否扫描了所有发生delete操作的block。

创建测试表test,c1是varchar2类型,并创建普通B树索引。

drop table test purge;

create table test (
id number not null,c1 varchar2(40),c2 varchar2(50))
PARTITION BY RANGE(id)
(
PARTITION PART01 VALUES LESS THAN (1000000),
PARTITION PART02 VALUES LESS THAN (2000000),
PARTITION PART03 VALUES LESS THAN (3000000),
PARTITION PART04 VALUES LESS THAN (4000000),
PARTITION PART05 VALUES LESS THAN (5000000),
PARTITION PART06 VALUES LESS THAN (6000000),
PARTITION PART07 VALUES LESS THAN (7000000),
PARTITION PART08 VALUES LESS THAN (8000000),
PARTITION PART09 VALUES LESS THAN (9000000),
PARTITION PART10 VALUES LESS THAN (10000000),
PARTITION PARTMAX VALUES LESS THAN (MAXVALUE)
)
tablespace enmotech;

create index idx1_test_c1 on test(c1) tablespace enmotech;
分批往不同分区中插入大量数据,保障C1列是单向递增,并发生90-10 leaf node split索引分裂。

begin
for i in 1..999999
loop
insert into test values(i ,concat('9a',to_char(sysdate,'yyyymmddhh24MISS')+i),rpad(' enmotech ',10));
commit;
end loop;
end;
/

SQL> @stat

     VALUE NAME
---------- ----------------------------------------------------------------
      4016 leaf node splits
      4016 leaf node 90-10 splits
        11 branch node splits
         1 root node splits


begin
    for i in 1000001..1999999 loop
        insert into test values(i ,concat('9a',to_char(sysdate,'yyyymmddhh24MISS')+i),rpad(' enmotech ',10));
        commit;
    end loop;
end;
/

SQL> @stat

     VALUE NAME
---------- ----------------------------------------------------------------
      8032 leaf node splits
      8032 leaf node 90-10 splits
        23 branch node splits
         1 root node splits

。。。

我们也模拟undo表空间不足导致truncate partition update global index失败的场景。

SQL> alter table test truncate partition part01 update global indexes;
alter table test truncate partition part01 update global indexes
            *
ERROR at line 1:
ORA-00604: error occurred at recursive SQL level 1
ORA-30036: unable to extend segment by 8 in undo tablespace 'UNDOTBS'

等回滚结束,开启10224 event并继续往test测试表中批量插入数据。

alter session set events '10224 trace name context forever, level 1';

begin
    for i in 5000001..5009999 loop
        insert into test values(i ,concat('9a',to_char(sysdate,'yyyymmddhh24MISS')+i),rpad(' enmotech ',10));
        commit;
    end loop;
end;
/

查看trace信息,第一次索引分裂相对后续的分裂时间更久,扫描的索引块也更多。

splitting leaf,dba 0x0140dc65,time 16:47:29.315
kdisnew_bseg_srch_cbk reject block -mark full,dba 0x01402edf,time 16:47:29.315
kdisnew_bseg_srch_cbk rejecting block ,dba 0x01402edf,time 16:47:29.315
kdisnew_bseg_srch_cbk reject block -mark full,dba 0x01402ee3,time 16:47:29.315
kdisnew_bseg_srch_cbk rejecting block ,dba 0x01402ee3,time 16:47:29.315
kdisnew_bseg_srch_cbk reject block -mark full,dba 0x01402ee7,time 16:47:29.315
kdisnew_bseg_srch_cbk rejecting block ,dba 0x01402ee7,time 16:47:29.315
kdisnew_bseg_srch_cbk reject block -mark full,dba 0x01402eeb,time 16:47:29.315
kdisnew_bseg_srch_cbk rejecting block ,dba 0x01402eeb,time 16:47:29.315
kdisnew_bseg_srch_cbk reject block -mark full,dba 0x01402eef,time 16:47:29.315
kdisnew_bseg_srch_cbk rejecting block ,dba 0x01402eef,time 16:47:29.315
kdisnew_bseg_srch_cbk reject block -mark full,dba 0x01402ef3,time 16:47:29.315
kdisnew_bseg_srch_cbk rejecting block ,dba 0x01402ef3,time 16:47:29.315
kdisnew_bseg_srch_cbk reject block -mark full,dba 0x01402ef7,time 16:47:29.315
kdisnew_bseg_srch_cbk rejecting block ,dba 0x01402ef7,time 16:47:29.315
kdisnew_bseg_srch_cbk reject block -mark full,dba 0x01402efb,time 16:47:29.315
kdisnew_bseg_srch_cbk rejecting block ,dba 0x01402efb,time 16:47:29.315
kdisnew_bseg_srch_cbk reject block -mark full,dba 0x01402eff,time 16:47:29.315
kdisnew_bseg_srch_cbk rejecting block ,dba 0x01402eff,time 16:47:29.315
kdisnew_bseg_srch_cbk reject block -mark full,dba 0x01402ec0,time 16:47:29.315
kdisnew_bseg_srch_cbk rejecting block ,dba 0x01402ec0,time 16:47:29.315
kdisnew_bseg_srch_cbk reject block -mark full,dba 0x01402ec4,time 16:47:29.315
kdisnew_bseg_srch_cbk rejecting block ,dba 0x01402ec4,time 16:47:29.315
kdisnew_bseg_srch_cbk reject block -mark full,dba 0x01402ec8,time 16:47:29.315
kdisnew_bseg_srch_cbk rejecting block ,dba 0x01402ec8,time 16:47:29.315
kdisnew_bseg_srch_cbk reject block -mark full,dba 0x01402ecc,time 16:47:29.315
kdisnew_bseg_srch_cbk rejecting block ,dba 0x01402ecc,time 16:47:29.315
kdisnew_bseg_srch_cbk reject block -mark full,dba 0x01402ed0,time 16:47:29.315
kdisnew_bseg_srch_cbk rejecting block ,dba 0x01402ed0,time 16:47:29.315

分析此次批量插入后kdisnew_bseg_srch_cbk操作扫描了很多数据块,rejecting block-意味着这些数据块不满足空闲块的要求,通过dba信息可以找出这些块对应在IDX1_TEST_C1索引块上。

SQL> @rdba
Enter value for rdba: 1402edf
old   1: SELECT dbms_utility.data_block_address_block(to_number('&rdba','xxxxxxxx')) "BLOCK",
new   1: SELECT dbms_utility.data_block_address_block(to_number('1402edf','xxxxxxxx')) "BLOCK",
Enter value for rdba: 1402edf
old   2:         dbms_utility.data_block_address_file(to_number('&rdba','xxxxxxxx')) "FILE"
new   2:         dbms_utility.data_block_address_file(to_number('1402edf','xxxxxxxx')) "FILE"

     BLOCK       FILE
---------- ----------
     11999          5

SQL> @extent
Enter value for fileid: 5
old   3: WHERE FILE_ID = &fileid
new   3: WHERE FILE_ID = 5
Enter value for blockid: 11999
old   4:  AND &blockid BETWEEN BLOCK_ID AND BLOCK_ID + BLOCKS - 1
new   4:  AND 11999 BETWEEN BLOCK_ID AND BLOCK_ID + BLOCKS - 1

OWNER    SEGMENT_NAME         SEGMENT_TYPE       TABLESPACE_NAME
-------- -------------------- ------------------ ---------------
SYS      IDX1_TEST_C1         INDEX              ENMOTECH

通过DUMP INDEX BLOCK可以看出这些索引分裂扫描的这些block都是IDX1_TEST_C1索引上part01分区数据对应的索引块。所以第一次发生分裂的时候SQL会产生很大的逻辑读和物理读。
在ASSM表空间中,索引数据块的空闲块都是通过三层位图管理结构,整个位图三级位图结构是一个树形结构,L3往往代表的就是Segment Header,L3中记录了所包含的所有L2位图块的地址,L2位图块中又包含了所属L1位图块地址。L1位图块中记录了具体数据块的地址和使用情况。L3,L2,L1三层结构均以树形结构,一对多的关系。
Update global index失败后,分区对应索引上的block在bitmap位图上会从FULL Blocks标记为”空闲块”,可以通过存储过程show_space进行测试。

SQL> set serveroutput on
SQL> exec show_space('IDX1_TEST_C1','SYS','INDEX');
Unformatted Blocks .....................               0
FS1 Blocks (0-25)  .....................               0
FS2 Blocks (25-50) .....................             272
FS3 Blocks (50-75) .....................               0
FS4 Blocks (75-100).....................               0
Full Blocks        .....................          24,105
Total Blocks............................          24,576
Total Bytes.............................     201,326,592
Total MBytes............................             192
Unused Blocks...........................               0
Unused Bytes............................               0
Last Used Ext FileId....................               5
Last Used Ext BlockId...................          76,800
Last Used Block.........................           1,024

PL/SQL procedure successfully completed.

SQL> alter table test truncate partition part01 update global indexes;
alter table test truncate partition part01 update global indexes
            *
ERROR at line 1:
ORA-00604: error occurred at recursive SQL level 1
ORA-30036: unable to extend segment by 8 in undo tablespace 'UNDOTBS'

SQL> exec show_space('IDX1_TEST_C1','SYS','INDEX');
Unformatted Blocks .....................               0
FS1 Blocks (0-25)  .....................               0
FS2 Blocks (25-50) .....................           3,769
FS3 Blocks (50-75) .....................               0
FS4 Blocks (75-100).....................               0
Full Blocks        .....................          20,608
Total Blocks............................          24,576
Total Bytes.............................     201,326,592
Total MBytes............................             192
Unused Blocks...........................               0
Unused Bytes............................               0
Last Used Ext FileId....................               5
Last Used Ext BlockId...................          76,800
Last Used Block.........................           1,024

PL/SQL procedure successfully completed.

分区truncate失败前后对比,索引的Total Blocks仍然是24576个,共有3497个索引块从“Full Blocks”标记为“FS2 Blocks (25-50)”,空闲比率25%~50%。下次发生索引分裂时就会多扫描3497个索引块,会导致IO的多消耗,在高并发场景下也继而会导致索引分裂的争用。
以上leaf node 90-10分裂模拟需要插入大量的数据,可以根据这个测试用例模拟leaf node 50-50分裂,只需插入一个中间值就会出现一次分裂,从而得出测试结果。

6 故障案例分析总结

每月2日凌晨00:30分自动清理任务开始清理ENMO_LOG_INFO表的历史分区,2月2日节点1系统crontab定时任务开始清理202012月分区,执行truncate partition update global index,UNDOTBS1被大量占用。
节点2上统计信息收集在02:00开始运行,统计信息采集的会话在采集索引IDX_ENMO_LOG_INFO_NEW_02统计信息时,由于节点1上在执行truncate partition操作,节点2统计信息会话会读取UNDOTBS1上一致性块(一致性读),在02:54由于UNDOTBS1单个roll segment回滚段无法扩展而失败,回滚段持续回收shrink。
节点1上的会话由于UNDOTBS1被truncate partition占用,节点2上的统计信息job进程当采集到表ENMO_LOG_INFO和索引IDX_ENMO_LOG_INFO_NEW_02时,采集SQL的物理读都发生在UNDOTBS1表空间上,在02:58:54开始报ORA-01555错误,报错中显示是UNDOTBS1快照过旧。
早上8点50分开始ENMO_LOG_INFO表上索引出现分裂,导致大量insert会话被阻塞,第一个index split的会话1744就是阻塞源头,1744的insert操作执行约369秒,大部分时间都是在gc等待和索引单块物理读上,因凌晨统计信息采集在节点2,因此gc量比较多,同时ENMO_LOG_INFO表凌晨清理数据失败,数据量较多导致索引分裂在寻找free block时扫描了索引IDX_ENMO_LOG_INFO_NEW_02上对应的202012数据的所有索引块,约9.3GB。表ENMO_LOG_INFO是日志表,索引列数据也是单向递增,并发量较大时也比较容易导致leaf node split。
本次数据库故障主要是发生在索引IDX_ENMO_LOG_INFO_NEW_02上的分裂导致,1744会话在8点50分时做INSERT操作,并触发索引分裂操作,导致300个同样的INSERT操作会话被阻塞。1744会话的索引分裂时间超过6分钟,耗时较长。

7 故障案例处理建议

导致本次故障的主要根因是凌晨的数据清理工作失败,影响了早上8点55开始1744会话的索引分裂(leaf split)操作,大量的索引物理单块读和GC读导致分裂过程耗时较长,继而导致大量的会话阻塞。主要有以下几点建议:
将数据清理的窗口放在凌晨0~2点执行,规避统计信息采集窗口;
保留更少的表数据,目前表数据保留2~3个月的数据,考虑按天分区,保留尽量少的数据量;
将统计信息采集任务通过SCHEDULER_JOB固定在单个节点执行;
索引所在列是单向递增,并且insert并发量较大,可以考虑对字段中数据做分散,继而将数据打散;
目前索引是全局索引,建议改造成二级分区索引,一级是range本地分区索引,二级是HASH索引,一级分区可以有效减少索引数据量并便于数据定期清理,二级分区可以有效打散单向递增的数据,减少索引leaf node split的现象也提高并发处理能力。

举报

相关推荐

0 条评论