在某次客户案例中,遇到了数据库无法启动的一则案例,根据现场工程师的反馈,获得了启动时的10046跟踪。在跟踪文件中,末端呈现的是大量的TT锁等待(这是一个10.2.0.4版本的数据库)。
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版本,如图4-1所示。
图4-1
其实DBA_FREE_SPACE视图的结构在不同版本之间变化较大,尤其是回收站引入之后。查询DBA_FREE_SPACE可能极慢并且可能触发问题,在监控表空间变化时,应当注意这些问题。