来自Oracle

作者：Arup Nanda

使用Oracle 10g中的等待界面诊断性能问题。

John是Acme银行的数据库管理员，电话另一端是愤怒的用户Bill，他抱怨他的数据库会话被挂起来了，对这种抱怨大多数数据库管理员是再熟悉不过了。John怎么才能打消Bill的抱怨呢？

Acme银行的数据库是Oracle数据库10g，因此John有很多种选择。自动数据库诊断管理器（ADDM）是Oracle数据库10g的新特性，它可以告诉John数据库当前的整体状态和性能，因此John一开始就用ADDM来确定Bill的会话正在经历的是否是数据库范围内的问题。ADDM报告确认没有能对Bill的会话产生这种影响的数据库范围内的问题，因此John继续考虑下一种选择。

一种诊断会话级事件（如Bill的问题）的方法就是确定会话是否正在等待什么事件，如文件块的读操作或表行上的锁或栓。从Oracle7开始，Oracle就提供了多种机制来显示数据库内发生的等待，而且在最近几年里，这一产品在不断地完善，加入了越来越多的诊断信息。在Oracle数据库10g中，提供了经过重大改进的等待事件信息，使诊断一个会话的速度减慢的问题变得更加容易。本文告诉你如何使用Oracle数据库10g中的等待事件来确定瓶颈问题。

会话等待

数据库管理员John如何才能确定是什么引起了Bill的会话挂起呢？实际上，会话并没有挂起；它正等待一个事件的发生，而这正是John要检查的。

John要继续其调查可以使用Oracle企业管理器或者直接通过命令行访问V$视图。John有一套用于诊断这些类问题的脚本，因此他使用命令行。

John查询V$SESSION视图来看一下Bill的会话正在等待什么。（请注意John过滤掉了所有空闲事件。）

select sid, username, event, blocking_session,
   seconds_in_wait, wait_time
from v$session where state in ('WAITING')
and wait_class != 'Idle';

下面以垂直格式给出输出结果。

SID              : 270
USERNAME         : BILL
EVENT            : enq: TX - row lock
                 contention
BLOCKING_SESSION : 254
SECONDS_IN_WAIT  : 83
WAIT_TIME        : 0

看到这些信息，John立刻得出结论，Bill的SID 270会话正在等待一个表上的锁，而这个锁正由254会话(BLOCKING_SESSION)占用。

但是John想知道哪条SQL语句引起了这个锁的占用。他可以通过连接V$SESSION和V$SQL视图执行下面的查询很容易地找到答案：

select sid, sql_text
from v$session s, v$sql q
where sid in (254,270)
and (
   q.sql_id = s.sql_id or
   q.sql_id = s.prev_sql_id);

代码清单1显示了查询结果。John看到（在清单1中）两个会话都试图更新同一行。除非会话254提交或回滚，否则会话270将一直等待这个锁。他向Bill解释了这一切，而Bill现在也不那么生气了，他认为应用程序中的有些东西出了问题，因此要求John结束会话254，以释放锁。

等待类

John结束了妨碍Bill的会话后，Bill的会话可以继续进行但是很慢。John决定检查该会话中的其他问题。他又一次检查看是否有任何其他等待事件，但这次他特别检查Bill的会话。

在Oracle数据库10g中，等待事件根据事件的类型分为不同的等待类。将事件分组使你能够将精力集中在特定的类上，而排除那些不重要的事件，如空闲事件。John对V$SESSION_WAIT_CLASS视图执行下面的查询：

select wait_class_id, wait_class,
   total_waits, time_waited
from v$session_wait_class
where sid = 270;

代码清单2给出输出结果，它显示出等待类，以及在每个类中会话等待事件的次数。它告诉John，自实例启动后与该应用程序相关的等待，如那些由于行级锁引起的等待出现了17760次，所花费的时间总共为281654厘秒(百分之一秒，cs)。John认为对于这个会话，TIME_WAITED的值太高了。他决定在该application（应用程序）等待类中寻找引起这些等待的原因。在V$SYSTEM_EVENT视图中可以获得每种等待的出现次数。他执行下面的查询来确定application等待类（类id 4217450380）中的每种等待：

select event, total_waits, time_waited
from v$system_event e, v$event_name n
where n.event_id = e.event_id
and wait_class_id = 4217450380;

代码清单3列出了该查询的输出结果。该结果显示，在application等待类的等待时间中，锁的争用（由事件enq: TX - row lock contention标识）占了大部分。这与John有关系。是不是编写得不好的应用程序有可能直接进入了产品数据库，从而引起这些锁的争用问题？

但是，作为一名经验丰富的DBA，John没有立即下这个结论。代码清单3中的数据仅仅表明用户经历了2275次与锁争用有关的等待，共计花费280856厘秒。有可能大多数等待只有1到2厘秒，所有等待时间可能仅仅是由一个长的等待引起的，在这种情况下，该应用程序并没有问题。单个长的等待也许是出现了反常现象它扭曲了数据，而并不代表系统的真正工作负载。John如何确定是否是一个单一等待事件扭曲了该数据呢？

Oracle 10g提供了一种新的视图，V$EVENT_HISTOGRAM，它显示等待时间周期以及会话等待某一特定时间周期的频度。Jone对V$EVENT_HISTOGRAM执行下面的查询语句：

select wait_time_milli bucket, wait_count
 from v$event_histogram
 where event =
    'enq: TX - row lock contention';

输出结果如下：

    BUCKET     WAIT_COUNT
-----------    ----------
         1         	  252
         2          	   0
         4          	   0
         8          	   0
        16          	   1	
        32          	   0
        64           	  4
       128          	  52
       256         	  706
       512        	   392
      1024         	   18
      2048         	    7
      4096        	   843

V$EVENT_HISTOGRAM视图显示等待时间段以及在这期间会话等待某一特定事件--在本例中就是行级锁争用--的次数。例如，会话等待少于1毫秒（ms）的事件共252次，等待大于1毫秒少于16毫秒的事件1次，等等。WAIT_COUNT列值之和为2275，与代码清单3列出的事件enq:TX - row lock contention中显示的值相同。V$EVENT_HISTOGRAM视图显示，大多数等待发生在256毫秒、512毫秒和4096毫秒的事件上，这就充分证明了该应用程序正在经历锁的争用问题，而这个锁的争用问题就是导致Bill的会话速度减慢的原因。如果视图显示等待发生在1毫秒的范围内，那么John就不能这么认为，因为这样短时间的等待似乎是正常的。

时间模型

刚刚给Bill解释完他的初步发现，Lora就走了进来，也带着类似的抱怨：她的SID 355会话非常慢。 John又一次通过对V$SESSION视图执行下面的查询来寻找该会话等待的事件：

select event, seconds_in_wait, 
   wait_time
from v$session
where sid = 355;

代码清单4列出的输出结果显示，Lora的会话中有各种各样的等待事件，包括栓（latch）争用，它表明一个应用程序的设计可能有问题。但是，John在给Lora提供修改应用程序的方法之前，他必须用事实来支持他的理论，即该应用程序设计的不好导致了Lora的会话性能低下。为了测试他的理论，他决定要确定Lora会话对资源的利用是否格外高，以及除了这个会话以外其他会话的速度是否也很慢。

在Oracle数据库10g的Time Model（时间模型）界面中，John可以轻松查看在各种活动中会话所用时间的详细情况。他对V$SESS_TIME_MODEL视图执行下面的查询语句：

select stat_name, value
from v$sess_time_model 
where sid = 355;
 

OS统计数据

在仔细检查用户的性能问题时，John还需要排除主机系统是瓶颈的可能性。在采用Oracle 10g以前，他可以使用操作系统（OS）工具，如sar 和vmstat，并推断出一些确定争用问题的度量指标。在Oracle 10g中，在数据库中自动采集OS级别的度量指标。为了查看潜在的主机争用问题，John对V$OSSTAT视图执行下面的查询：

select * from v$osstat;

代码清单6给出的输出结果显示了所采集的OS级别的各种度量指标元素。所有时间元素都以厘秒为单位。从代码清单6显示的结果中John了解到，系统的一个CPU有51025805厘秒空闲（IDLE_TICKS）、2389857厘秒繁忙（BUSY_TICKS），这表明CPU有大约4%的时间繁忙。从中他得出结论，在主机中CPU不是瓶颈。请注意，如果主机系统有多于1个的CPU，则标头中有AVG_前缀的列，如AVG_IDLE_TICKS将显示所有CPU的这些度量指标的平均值。

活动会话的历史

到目前为止，每当发生问题时用户就向John咨询，使他能实时地查看性能状况。没过多久Janice又找到John，抱怨最近出现的性能问题。当John查询V$SESSION视图时，会话是空闲的，没有正在等待的事件。John如何检查Janice的会话出现问题时正在等待什么事件呢？

Oracle 10g在内存缓冲区内每秒采集一次活动会话的信息。这个缓冲区被称为活动会话历史（Active Session History，ASH），可以在V$ACTIVE_SESSION_HISTORY动态性能视图中查看它，其中的数据在被新数据周期性地覆盖前保留30分钟。John得到Janice会话的SID和SERIAL#，然后对V$ACTIVE_SESSION_HISTORY视图执行以下查询，以便找出会话过去等待的事件。

select sample_time, event, wait_time
from v$active_session_history
where session_id = 271
and session_serial# = 5;

select sql_text, application_wait_time
from v$sql
where sql_id in (
  select sql_id
  from v$active_session_history
  where sample_time = 
   '22-FEB-04 03.17.31.188 PM'
  and session_id = 271
  and session_serial# = 5
);

输出结果如代码清单8所示。

APPLICATION_WAIT_TIME列显示执行该SQL的会话等待了多长时间的application等待类。除了SQL_ID，V$ACTIVE_SESSION_HISTORY视图还使John了解了被等待的具体行（在锁争用的情况下）、客户端标识符以及其它信息。

如果用户晚一点儿找John，视图中的数据已经被覆盖了，那该怎么办呢？当数据从这个动态性能视图中清除时，这些数据被送到活动工作负载信息库（Active Workload Repository，AWR）中，它是一个基于磁盘的信息库。被清除的ASH（活动会话历史）数据可以在DBA_HIST_ACTIVE_SESSION_HIST视图中看到，这使John能够看到过去的会话的等待事件。在默认状态下，AWR中的数据7天后即被清除。

结论

Oracle数据库10g引入了许多增强特性，它们是为了简化性能诊断过程并使其自动化而设计的。Oracle数据库10g的等待事件信息是经过精心设计的，从而提供了对问题起因的更加深入的洞察力，这使得在大多数情况下，特别是在主动性能调优时诊断性能问题轻而易举。

Arup Nanda ([email protected]) 是位于纽约白原市的Starwood酒店及度假村的数据库系统经理。他是Oracle杂志2003年度最佳DBA奖获得者，还是Rampant出版公司(rampant-books.com)出版的《Oracle Privacy Security Auditing（Oracle保密性安全审计技术）》一书的合著者。

发表评论

IT瘾于2007年7月19日 下午04时52分56秒发布 #