暂无图片
暂无图片
1
暂无图片
暂无图片
暂无图片

Oracle DBA核心技能:通过10046解决数据库RAC集群不能启动案例

原创 eygle 2020-02-04
2426

在某次客户案例中,遇到了数据库无法启动的一则案例,根据现场工程师的反馈,获得了启动时的10046跟踪。在跟踪文件中,末端呈现的是大量的TT锁等待(这是一个10.2.0.4版本的数据库)。
image.png

WAIT #2: nam='enq: TT - contention' ela= 488293 name|mode=1414791174 tablespace ID=0 operation=0 obj#=-1 tim=6632936391
WAIT #2: nam='enq: TT - contention' ela= 488294 name|mode=1414791174 tablespace ID=0 operation=0 obj#=-1 tim=6633424737
WAIT #2: nam='enq: TT - contention' ela= 488292 name|mode=1414791174 tablespace ID=0 operation=0 obj#=-1 tim=6633913072
WAIT #2: nam='enq: TT - contention' ela= 488292 name|mode=1414791174 tablespace ID=0 operation=0 obj#=-1 tim=6634401394
WAIT #2: nam='enq: TT - contention' ela= 488292 name|mode=1414791174 tablespace ID=0 operation=0 obj#=-1 tim=6634889716
WAIT #2: nam='enq: TT - contention' ela= 488293 name|mode=1414791174 tablespace ID=0 operation=0 obj#=-1 tim=6635378039
WAIT #2: nam='enq: TT - contention' ela= 488292 name|mode=1414791174 tablespace ID=0 operation=0 obj#=-1 tim=6635866366

找到最后执行的递归SQL,从这一点开始分析,主要信息显示如下。

=====================
PARSING IN CURSOR #3 len=348 dep=1 uid=0 oct=3 lid=0 tim=5645840078 hv=2512561537 ad='b5f8e850'
select name,intcol#,segcol#,type#,length,nvl(precision#,0),decode(type#,2,nvl(scale,-127/*MAXSB1MINAL*/), 178,scale,179,scale,180,scale,181,scale,182,scale,183,scale,231,scale,0),null$,fixedstorage,nvl(deflength,0),default$,rowid,col#,property, nvl(charsetid,0),nvl(charsetform,0),spare1,spare2,nvl(spare3,0) from col$ where obj#=:1 order by intcol#
END OF STMT
EXEC #3:c=0,e=118,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=5645840075
FETCH #3:c=0,e=52,p=0,cr=3,cu=0,mis=0,r=1,dep=1,og=4,tim=5645840215
STAT #3 id=1 cnt=130 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=35 pr=0 pw=0 time=732 us)'
STAT #3 id=2 cnt=130 pid=1 pos=1 obj=21 op='TABLE ACCESS CLUSTER COL$ (cr=35 pr=0 pw=0 time=330 us)'
STAT #3 id=3 cnt=11 pid=2 pos=1 obj=3 op='INDEX UNIQUE SCAN I_OBJ# (cr=22 pr=0 pw=0 time=102 us)'
WAIT #2: nam='DFS lock handle' ela= 450 type|mode=1413545989 id1=4 id2=0 obj#=-1 tim=5645841105
WAIT #2: nam='DFS lock handle' ela= 445 type|mode=1413545989 id1=2 id2=0 obj#=-1 tim=5645841592
WAIT #2: nam='enq: US - contention' ela= 443 name|mode=1431502854 undo segment #=0 0=0 obj#=-1 tim=5645842085
WAIT #2: nam='gc current block 2-way' ela= 1420 p1=1 p2=9 p3=16777231 obj#=-1 tim=5645843634
WAIT #2: nam='gc current grant busy' ela= 516 p1=1 p2=9 p3=33619983 obj#=-1 tim=5645844244
WAIT #2: nam='rdbms ipc reply' ela= 637 from_process=17 timeout=900 p3=0 obj#=-1 tim=5645844928
WAIT #2: nam='enq: TT - contention' ela= 488657 name|mode=1414791174 tablespace ID=0 operation=0 obj#=-1 tim=5646333647
WAIT #2: nam='enq: TT - contention' ela= 488293 name|mode=1414791174 tablespace ID=0 operation=0 obj#=-1 tim=5646821976

等待事件是分析的起点,而真正能够理解等待事件后面隐藏的深意是DBA不断成长的重要标志。
第一个需要分析清楚的是DFS lock handle,该事件出现了两次。

WAIT #2: nam='DFS lock handle' ela= 450 type|mode=1413545989 id1=4 id2=0 obj#=-1 tim=5645841105
WAIT #2: nam='DFS lock handle' ela= 445 type|mode=1413545989 id1=2 id2=0 obj#=-1 tim=5645841592

DFS 是 Distributed File System 的缩写,最早在Oracle并行服务器(OPS)时代引入,指分布式集群文件系统,但是今天这个DFS涵盖的意义更加广泛,这里代表着需要获取一个全局锁。之所以加上Handle,是因为很多锁的获取是分为两个步骤,首先获得lock handle上的锁定。这里的DFS给我们的提示是,这是一个RAC环境,而事实上,另外一个节点还在正常运行,当前故障节点无法启动。
由于Oracle的锁类型很多,这个事件的一个参数是type|mode,通过这个参数合并编码了锁类型和请求模式。可以通过SQL将这两个元素解码出来。

select chr(bitand(&&p1,-16777216)/16777215) ||
   chr(bitand(&&p1,16711680)/65535) type, mod(&&p1, 16) md
from dual;
TY	   MD
-- ----------
TA	    5

查询得到的结论是TA锁,请求模式5。如果不熟悉TA这个锁类型,可以通过数据字典查询一下。

SQL> exec print_table('select * from v$lock_type where type=''TA''');
TYPE                  : TA
NAME                  : Instance Undo
ID1_TAG               : operation
ID2_TAG               : undo segment # / other
IS_USER               : NO
IS_RECYCLE              : NO
DESCRIPTION             : Serializes operations on undo segments and undo tablespaces
CON_ID                   : 0
-----------------

以上print_table引用了一个Tom的脚本,其内容如下所示。

create or replace procedure print_table( p_query in varchar2 )
AUTHID CURRENT_USER
is
    l_theCursor     integer default dbms_SQL.open_cursor;
    l_columnValue   varchar2(4000);
    l_status        integer;
    l_descTbl       dbms_SQL.desc_tab;
    l_colCnt        number;
begin
    execute immediate
    'alter session set 
        nls_date_format=''dd-mon-yyyy hh24:mi:ss'' ';

    dbms_SQL.parse(  l_theCursor,  p_query, dbms_SQL.native );
    dbms_SQL.describe_columns
    ( l_theCursor, l_colCnt, l_descTbl );

    for i in 1 .. l_colCnt loop
        dbms_SQL.define_column
        (l_theCursor, i, l_columnValue, 4000);
    end loop;

    l_status := dbms_SQL.execute(l_theCursor);

    while ( dbms_SQL.fetch_rows(l_theCursor) > 0 ) loop
        for i in 1 .. l_colCnt loop
            dbms_SQL.column_value
            ( l_theCursor, i, l_columnValue );
            dbms_output.put_line
            ( rpad( l_descTbl(i).col_name, 30 )
              || ': ' || 
              l_columnValue );
        end loop;
        dbms_output.put_line( '-----------------' );
    end loop;
    execute immediate
        'alter session set nls_date_format=''dd-MON-rr'' ';
exception
    when others then
      execute immediate
          'alter session set nls_date_format=''dd-MON-rr'' ';
      raise;
end;
/

我们看到TA锁是Instance Undo——实例重做锁,其描述表明是和Undo段、Undo表空间相关的串行操作。
进一步锁定信息在下一个事件体现出来,成为显性的US锁等待。

WAIT #2: nam='enq: US - contention' ela= 443 name|mode=1431502854 undo segment #=0 0=0 obj#=-1 tim=5645842085

这里的name|mode转换出来,请求的是模式6——X的排它锁。

select chr(bitand(&&p1,-16777216)/16777215) ||
   chr(bitand(&&p1,16711680)/65535) type,
   mod(&&p1, 16) md from dual dual;
Enter value for p1: 1431502854 
TY     MD
-- ----------
US      6

再进一步,Oracle通过GC Current读向远程请求了文件1的第9个Block,但是在远程实例中这个请求没有被授予,呈现Busy的状态,也就是排它锁不能被获取。

WAIT #2: nam='gc current block 2-way' ela= 1420 p1=1 p2=9 p3=16777231 obj#=-1 tim=5645843634
WAIT #2: nam='gc current grant busy' ela= 516 p1=1 p2=9 p3=33619983 obj#=-1 tim=5645844244

再向下,数据库以TT锁等待处于无尽循环等待,数据库无法启动。

WAIT #2: nam='enq: TT - contention' ela= 488657 name|mode=1414791174 tablespace ID=0 operation=0 obj#=-1 
WAIT #2: nam='enq: TT - contention' ela= 488293 name|mode=1414791174 tablespace ID=0 operation=0 obj#=-1 

那么TT锁是什么?通过以下查询,可以看到这同样是串行表空间操作的DDL锁。

SQL> set serveroutput on
SQL> exec print_table('select * from v$lock_type where type=''TT''');
TYPE                  : TT
NAME                  : Tablespace
ID1_TAG              : tablespace ID
ID2_TAG              : operation
IS_USER              : NO
IS_RECYCLE              : NO
DESCRIPTION              : Serializes DDL operations on tablespaces
CON_ID                    : 0
-----------------

整个问题的脉络梳理清楚了,还剩下一个问题,为什么在数据库的启动过程中要在回滚段上获取串行DDL排他锁?文件1的Block 9给我们了一个线索,存活节点不能给予的锁定块到底是什么?

SQL> exec print_table('select segment_name,segment_type from dba_extents where file_id=1 and block_id=9');
SEGMENT_NAME        : SYSTEM
SEGMENT_TYPE        : ROLLBACK
-----------------

我们看到了输出结果,系统回滚段,那么数据库启动过程为何要在SYSTEM回滚段上获取排他锁呢?
回顾BOOTSTRAP$中的对象,数据库初始化中顺序执行的第一个语句就是CREATE ROLLBACK SEGMENT SYSTEM STORAGE,也就是分配系统回滚段。

CREATE ROLLBACK SEGMENT SYSTEM STORAGE 
( INITIAL 112K NEXT 1024K MINEXTENTS 1 MAXEXTENTS 32765 OBJNO 0 EXTENTS 
(FILE 1 BLOCK 9))

正是因为这样一个DDL操作需要获得排他锁,数据库在启动过程中才需要向存活实例发出锁请求,无法获得就只有等待。
这里需要注意,系统回滚段从11g开始,向后偏移至第128个Block。

CREATE ROLLBACK SEGMENT SYSTEM STORAGE (  INITIAL 112K NEXT 56K MINEXTENTS 1  MAXEXTENTS 32765 OBJNO 0 EXTENTS (FILE 1 BLOCK 128))

那么对方实例为什么无法给予授权?那一定是因为对方节点同样存在锁定。我们从存活实例上查询V$LOCK分析其当前锁定,发现同样存在大量的TT锁等待,而连接时间最长的会话CTIME已经长达8066215秒。

SQL> select * from gv$lock where type=‘TT';
   INST_ID ADDR         KADDR             SID TY        ID1ID2  LMODE REQUEST      CTIME BLOCK
---------- ------ ---------------- ---- -- ------------- ------ ------- ---------- -----
         1 07000002D8867018 07000002D8867038 2112 TT    0  0      0       4      12725     0
         1 07000002D88643B0 07000002D88643D0 2115 TT     0  0      0       4      13055     0
         1 07000002D88707D0 07000002D88707F0 2116 TT   0  0      4       0    8066215    2
         1 07000002D8864020 07000002D8864040 2116 TT     0  0      0       4      13385     0
         1 07000002D88644E0 07000002D8864500 2124 TT    0  0      0       4      10415     0
         1 07000002D88670B0 07000002D88670D0 2134 TT      0  0      0       4      11735     0
         1 07000002D88674D8 07000002D88674F8 2145 TT      0  0      0       4      10745     0
         1 07000002D8868BB0 07000002D8868BD0 2155 TT   0  0      4       0    8314633    2
         1 07000002D88673A8 07000002D88673C8 2155 TT   0  0      0       4      11405     0

注意这两个长时间的锁定,其BLOCK类型为2,这在官方文档上有明确的解释(文档v$lock视图部分),这样的进程阻塞了RAC环境远程的操作。

2 - The lock is not blocking any blocked processes on the local node, but it may or may not be blocking processes on remote nodes. This value is used only in Oracle Real Application Clusters (Oracle RAC) configurations (not in single instance configurations).

那么这些进程到底在执行什么操作?通过V$SESSION.SQL_ID发现这些SQL正在执行表空间的剩余空间计算工作。

SELECT a.ts_name,
  bytes/data_sum,
  data_sum,
  free_sum
FROM
  (SELECT tablespace_name ts_name,
    SUM(NVL(blocks,0)) data_sum,
    SUM(NVL(bytes,0)) bytes
  FROM dba_data_files
  GROUP BY tablespace_name
  )a,
  (SELECT tablespace_name ts_name,
    SUM(NVL(blocks,0)) free_sum
  FROM user_free_space
  GROUP BY tablespace_name
  )b
WHERE a.ts_name=b.ts_name
ORDER BY a.ts_name

通过手工Kill终止两个阻塞进程之后,数据库节点可以成功启动。通过MOS确认这是一个Bug,如果对于DBA_FREE_SPACE的查询未正常结束可能导致锁定无法释放,产生TT队列竞争,其影响范围甚至包括11.2.0.4版本,BUG号是:9439759 。

其实DBA_FREE_SPACE视图的结构在不同版本之间变化较大,尤其是回收站引入之后。查询DBA_FREE_SPACE可能极慢并且可能触发问题,在监控表空间变化时,应当注意这些问题。

最后修改时间:2020-02-04 23:42:35
「喜欢这篇文章,您的关注和赞赏是给作者最好的鼓励」
关注作者
【版权声明】本文为墨天轮用户原创内容,转载时必须标注文章的来源(墨天轮),文章链接,文章作者等基本信息,否则作者和墨天轮有权追究责任。如果您发现墨天轮中有涉嫌抄袭或者侵权的内容,欢迎发送邮件至:contact@modb.pro进行举报,并提供相关证据,一经查实,墨天轮将立刻删除相关内容。

评论