技术开发 频道

异常终止会话导致系统被Hung

  【IT168 技术文档】问题和现象

  接到生产支持的同事报告:数据库反应非常慢,很多数据库操作无法完成,DB出在被hung住的状态。同时,他们通过OEM发现其中一个节点(我们的数据库是10G RAC环境,3个节点)上发现存在很高的“Active Sessions Waiting: Other”的waits,见下图:

  分析

  "Active Sessions Waiting: Other"这一类的Waits是统计了RAC数据库中除IO和Idle waits之外的所有waits事件,要分析造成这些waits的原因,我们需要知道具体是那些event导致的waits。由上图中问题出现的时间段,我取了9月1号13:00到9月2号12:00之间awr report进行进一步分析。从awr report的top events中,得到了有价值的东西:

  我们可以看到,Top 5 events中,有2个events是属于Other的,也就是说,这2个event是导致系统"Active Sessions Waiting: Other"异常的根本原因。我们再具体分析这2个events。

  "DFS lock handle"这一event是在RAC环境中,会话等待获取一个全局锁的句柄时产生的。在RAC中,全局锁的句柄是由DLM(Distributed Lock Manager 分布式锁管理器)所管理和分配的。大量发生这一event说明全局锁句柄资源不够分配了。决定DLM锁数量的参数是_lm_locks,9i以后,它是一个隐含参数,默认值是12000。没有特殊情况,这一值对于一个OLTP系统来说是足够的。我们不能盲目地直接增加资源,而是需要找到导致资源紧张的根本原因。锁资源紧张,说明存在大量事务获取了锁,但是事务没有提交、回滚。那么,又是什么导致了这些事务不结束呢?应用程序代码不完善,没有提交事务?或者那些事务还在等待别的资源?分析到此,我们暂时先放下这一event,看下top event中的另外一个异常event。

  "enq: US - contention",这个event说明事务在队列中等待UNDO Segment,通常是由于UNDO空间不足导致的。结合对前一event的分析,初步判断正是因为大量事务在等待队列中等待UNDO资源,导致全局锁没有释放。为了验证这一判断,我分别查询发生这2个events的对象是那些。先看"DFS lock handle"的wait对象:

  SQL代码

 select o.object_id, o.owner, o.object_name, o.subobject_name, o.object_type, s.cnt

  
from dba_objects o,

  (
select current_obj#, count(*) cnt from dba_hist_active_sess_history

  
where snap_id between 14315 and 14338

  
and event='DFS lock handle'

  
group by current_obj#) s

  
where object_id = s.current_obj#

  
order by cnt desc;

  
OBJECT_ID OWNER OBJECT_NAME SUBOBJECT_NAME OBJECT_TYPE CNT

  
---------- ------------------ ------------------------ ----------------- -------------- ----------

  
121517 CS2_PARTY_OWNER PARKING_LOT_TXN_PK INDEX 1524

  
121525 CS2_PARTY_OWNER PARKING_LOT_SHMT_IDX2 INDEX 1074

  
121518 CS2_PARTY_OWNER PARKING_LOT_TXN_IDX1 INDEX 984

  
121430 CS2_PARTY_OWNER PARKING_LOT_TXN TABLE 664

  
121524 CS2_PARTY_OWNER PARKING_LOT_SHMT_IDX1 INDEX 606

  
121516 CS2_PARTY_OWNER PARKING_LOT_IDX3 INDEX 594

  
121523 CS2_PARTY_OWNER PARKING_LOT_SHMT_PK INDEX 524

  ... ...

  看到发生这一event的对象都是PARKING_LOT模块中的几个相关对象。再看"enq: US - contention"的对象:

  SQL代码

select o.object_id, o.owner, o.object_name, o.subobject_name, o.object_type, s.cnt

  
from dba_objects o,

  (
select current_obj#, count(*) cnt from dba_hist_active_sess_history

  
where snap_id between 14315 and 14338

  
and event='enq: US - contention'

  
group by current_obj#) s

  
where object_id = s.current_obj#

  
order by cnt desc;

  
OBJECT_ID OWNER OBJECT_NAME SUBOBJECT_NAME OBJECT_TYPE CNT

  
---------- ----------------- ----------------------- ----------------- ------------ ----------

  
121517 CS2_PARTY_OWNER PARKING_LOT_TXN_PK INDEX 1447

  
121525 CS2_PARTY_OWNER PARKING_LOT_SHMT_IDX2 INDEX 1095

  
121518 CS2_PARTY_OWNER PARKING_LOT_TXN_IDX1 INDEX 946

  
121430 CS2_PARTY_OWNER PARKING_LOT_TXN TABLE 586

  
121433 CS2_PARTY_OWNER PARKING_LOT_PK INDEX 482

  
121523 CS2_PARTY_OWNER PARKING_LOT_SHMT_PK INDEX 474

  
121516 CS2_PARTY_OWNER PARKING_LOT_IDX3 INDEX 461

  ... ...

  可以看到,发生这2个event的对象基本都是相同的对象。这一结果对之前的判断是一个很大的支持:"enq: US - contention"是导致"DFS lock handle"的原因,我们需要重点着手解决"enq: US - contention"问题。还是那句话:不要盲目增加资源,找到导致资源紧张的原因先。在我们的环境中,创建了3个UNDO Tablespace分别指定给了3个节点,管理方式是Auto的。每个UNDO表空间的大小是20G。在这之前,从来没有出现过UNDO资源不足的问题。

  首先,我想到一个可能是UNDO_RETENTION时间太长、且UNDO表空间被设置为GUARANTEE了。这样的话,会导致许多已经结束的事务的UNDO数据被保护起来不被使用,UNDO_RETENTION的时间越长,这些数据占用的UNDO空间就越多,这样就很容易导致"enq: US - contention"问题。从awr report中看到,UNDO_RETENTION的时间设置得确实比较长:7200秒。再看一下表空间是否被GUARANTEE了:

  SQL代码

select tablespace_name, retention from dba_tablespaces where tablespace_name like 'UNDO%';

  TABLESPACE_NAME RETENTION

  
------------------------------ -----------

  UNDOTBS1 NOGUARANTEE

  UNDOTBS2 NOGUARANTEE

  UNDOTBS3 NOGUARANTEE

  结果发现表空间并没有做retension guarantee,这一可能性被排除。

  那我们再看一下到底是那些事务占用了UNDO空间,结果出乎意料:

  SQL代码

SELECT a.sid, a.username, b.xidusn, b.used_urec, b.used_ublk, sq.sql_text

  
FROM v$session a, v$transaction b, v$sqlarea sq

  
WHERE a.saddr = b.ses_addr

  a.sql_address
= sq.address(+);

  SID USERNAME XIDUSN USED_UREC USED_UBLK SQL_TEXT

  
---------- ----------- ---------- ---------- ---------- -----------

  
1511 CS2_PARTY 1 9 1

  我们在该节点上并没有找到大量占用UNDO空间的事务的。那UNDO空间的实际使用情况到底是怎样的呢?

  SQL代码

 SELECT SEGMENT_NAME, TABLESPACE_NAME, BYTES, BLOCKS, EXTENTS, SEGMENT_TYPE

  
FROM DBA_SEGMENTS

  
WHERE SEGMENT_TYPE LIKE chr(37)||'UNDO'||chr(37)

  
order by TABLESPACE_NAME, bytes desc;

  SEGMENT_NAME TABLESPACE_NAME BYTES BLOCKS EXTENTS SEGMENT_TYPE

  
-------------- --------------- ---------- -------- ---------- ------------------

  _SYSSMU69$ UNDOTBS1
2.0709E+10 2528008 4615 TYPE2 UNDO

  _SYSSMU123$ UNDOTBS1
11141120 1360 170 TYPE2 UNDO

  _SYSSMU34$ UNDOTBS1
11010048 1344 168 TYPE2 UNDO

  ... ...

  找到症结了。_SYSSMU69$这个回滚段占据了19.3G的空间!再看看这个回滚段中的扩展段(extent)的状态:

  SQL代码

select status, sum(blocks)

  
from dba_undo_extents

  
where segment_name='_SYSSMU69$'

  
group by status;

  STATUS
SUM(BLOCKS)

  
--------- -----------

  ACTIVE
2528008

  全部扩展段都是active的,正常的话,说明有事务正在使用该回滚段的所有扩展段。但实际上却找不到这样的事务:

  SQL代码

select

  r.name "RBS name",

  t.start_time,

  t.used_ublk "Undo blocks",

  t.used_urec "Undo recs"

  
from

  gv$
transaction t,

  v$rollname r

  
where r.usn = t.xidusn

  
and r.name = '_SYSSMU69$';

  no rows selected

  这一点不正常。最大的可能性就是当初使用该回滚段的事务被异常终止了,导致资源没释放。这一点,通过与生产支持的同事确认,得到一个这样的事实:

  1号上午,他们发现报表系统的一个housekeeping在删除一个日志表的数据消耗大量资源,影响到其它模块的运行,于是先用Kill Session的方式杀掉会话,但是会话仍在运行(对于大事务来说,这很正常,kill session会回滚还未提交的事务,事务越大,回滚时间越久),于是就在操作系统上将该进程杀掉了。这个作业是凌晨1:00开始运行的,在删除这张表之前,会先删除其它几张表,这大概需要2、3个小时的时间,也就是说大概在4:00左右开始删除该表。那我们再查一下该回滚段是在什么时间开始激增的:

  SQL代码

 select begin_time,end_time,undotsn,undoblks,txncount,activeblks,unexpiredblks,expiredblks from v$undostat;

  
2009-09-01 05:19:01 2009-09-01 05:29:01 1 1268 7993 2529896 30048 48

  
2009-09-01 05:09:01 2009-09-01 05:19:01 1 1779 8916 2529896 30024 72

  
2009-09-01 04:59:01 2009-09-01 05:09:01 1 5745 14819 2529896 30024 72

  
2009-09-01 04:49:01 2009-09-01 04:59:01 1 78200 5120 2451832 104448 3712

  
2009-09-01 04:39:01 2009-09-01 04:49:01 1 114524 5213 2339672 115840 99360

  
2009-09-01 04:29:01 2009-09-01 04:39:01 1 102563 6448 2236904 123264 193680

  
2009-09-01 04:19:01 2009-09-01 04:29:01 1 144123 7370 2095304 189056 275632

  
2009-09-01 04:09:01 2009-09-01 04:19:01 1 110936 20206 1989672 308864 261456

  
2009-09-01 03:59:01 2009-09-01 04:09:01 1 80127 13635 1911464 367360 273744

  
2009-09-01 03:49:01 2009-09-01 03:59:01 1 107125 11822 1807576 499840 252576

  可以看到,正是在4:00左右开始急剧增长的。基本上我们可以确认正是这一异常操作导致大量的回滚段被占用也没被释放!

  由于该回滚段的状态处于ONLINE状态,且其所有扩展段都是ACTIVE的,所以我们不能DROP或SHRINK它。现在,我们有两个方案来解决该问题:

  由于对于的事务已经不存在了,我们无法通过提交或回滚事务来是否回滚段资源。那么,最直接的方法就是重启实例,重置回滚段;

  临时解决方案就是增加或者新建一个UNDO表空间,使其它事务能正常运行。

  第一个方案会影响到其它模块,只能到周末downtime的时候实施。于是采用第二个方案:临时增加了为UNDOTBS1增加了10g空间。在杀掉一些由于这些等待被彻底hung住的会话后,整个数据库恢复了正常。

0
相关文章