2.2 AWR概览
2.2.1 AWR报告的注意事项
AWR报告是进行健康检查时必不可少的工具。关于报告前面的Load Profile、TOP5等待等这些东西不再叙述,已经有太多相关资料。AWR的中后部有些信息值得注意,比如Instance Activity Stats。上一节讲了很多资料类视图相关的内容,如果AWR报告是30分钟产生一份,那么Instance Activity Stats其实就是这30分钟内各种资料的值。
不过这一部分内容很多人在阅读时往往忽略,但定位Oracle问题是这一部分内容中必不可少的。
除这一部分外,还有一些容易被忽视的,如I/O Stats部分。I/O始终是数据库的“命门”,I/O压力的不均衡,可能导致奇怪的问题。看如图2-18所示的这份AWR报告。
图2-18 AWR报告(一)
其中,unspecified wait event是一个奇怪的Event。从TOP 5来看,I/O响应时间都很正常,db file sequential read是1毫秒,db file scattered read是3毫秒,这两个值不仅正常,而且应该说是很不错。查看所有I/O相关的等待,Control file sequential read、Log file parallel write等,响应时间为几毫秒,可以排除是I/O问题造成的unspecified wait event。
但真的是这样吗?继续查看IO Stats部分,在Tablespace IO Stats 部分,发现有一个表空间的I/O响应延时远远高于正常水平,如图2-19所示。
从这部分可以看到,有一个表空间的I/O响应时间已经是1491毫秒了。再进一步查看File IO Stats部分,如图2-20所示。
还是刚才那个表空间,它有两个数据文件,I/O平均响应时间已经高达四五千毫秒了。也就是在此份AWR报告期间,这两个文件要平均四五秒才能完成一个I/O。
图2-19 AWR报告(二)
注:出于保密原因,表空间名称部分省去。
图2-20 AWR报告(三)
这只是平均值,说不定在某个时刻,I/O的响应时间比这个还要长。如果I/O过分的缓慢,产生一些奇怪的等待事件,如unspecified wait event,也就不足为奇了。
这份报告是晚上23点至23点30分产生的,当时这个数据库正在同时进行大概10个左右的大表加载数据操作,I/O量非常大,超过了存储的瓶颈,因此I/O响应时间很长。数据加载完成后,像unspecified wait event之类的奇怪等待事件再没有出现过。
在进一步诊断问题时,AWR报告后面的这部分内容其实为我们列出了很多有用的信息,平常在诊断问题时可以注意挖掘。
但说白了,AWR其实也只是把各种运行资料、等待事件组合起来显示而已,如何阅读AWR报告,建立在对这些资料、等待事件的理解基础上。如果不知道这些资料、等待事件的含义,一份报告根本无从看起。
在后面的章节中,每讲一部分内容,都先给出原理,然后根据原理介绍相关运行资料、等待事件的含义。
当然,Oracle中有很多等待事件和运行资料,本书不可能每个都详细讲到。实际上,学习挖掘、分析Oracle等待事件和运行资料含义的方法,比了解某个事件、资料的含义更有意义。授人以鱼,不如授人以渔。直接告诉你某个等待事件的意义,远不如告诉如何发掘等待事件的意义更重要。这将是本书后面章节的主要内容。
2.2.2 AWR类视图
AWR报告的底层有一系列以DBA_HIST_为前缀的视图,用于保存AWR的历史资料,Oracle每隔一定时间,写一份所有资料、等待事件类视图的快照到此类视图中,AWR报告中的大部分内容都来自这些快照。所有快照的信息都保存在DBA_HIST_SNAPSHOT视图中。如下语句可以查看最早的和最近的快照:
selectmax(BEGIN_INTERVAL_TIME),
min(BEGIN_INTERVAL_TIME),
max(SNAP_ID),
min(snap_id)
from DBA_HIST_SNAPSHOT ;
下面的语句可以查看快照的时间间隔和最早的快照编号:
setlinesize 1000
col BEGIN_INTERVAL_TIME for a40
select * from (select BEGIN_INTERVAL_TIME,SNAP_ID from DBA_HIST_SNAPSHOT order
by BEGIN_INTERVAL_TIME) where rownum<=10;
SQL> set linesize 1000
SQL> col BEGIN_INTERVAL_TIME for a40
SQL> select * from (select BEGIN_INTERVAL_TIME,SNAP_ID from DBA_HIST_SNAPSHOT
order by BEGIN_INTERVAL_TIME) where rownum<=20;
BEGIN_INTERVAL_TIME SNAP_ID
---------------------------------------- ----------
07-AUG-11 12.00.58.249 AM 26659
07-AUG-11 12.30.58.283 AM 26660
07-AUG-11 01.00.00.680 AM 26661
07-AUG-11 01.30.03.632 AM 26662
………………………………
可以看到,Oracle半小时产生一份快照。目前最早的一份快照是8月7日上午12点产生的,编号26659。
所有其他的DBA_HIST_视图基本上都有SNAP_ID列,可以根据此列关联。比如,如下语句查看从实例启动到8月10日9点时的物理读信息:
setlinesize 1000
col BEGIN_INTERVAL_TIME for a40
selecta.BEGIN_INTERVAL_TIME,
a.SNAP_ID,
b.stat_name,
b.value
from DBA_HIST_SNAPSHOT a,DBA_HIST_SYSSTAT b
wherea.BEGIN_INTERVAL_TIME>=to_date('2011-08-10 09:00:00')
anda.BEGIN_INTERVAL_TIME<=to_date('2011-08-10 09:29:00')
and b.SNAP_ID=a.SNAP_ID
andb.stat_name like 'physical reads' ;
BEGIN_INTERVAL_TIME SNAP_ID STAT_NAME VALUE
-------------------------------------------------- ---------
10-AUG-11 09.00.53.960 AM 26816 physical reads 6285630462
因为AWR是半小时产生一次快照,有时快照的时间点不是整点,所以上述条件是从9点至9点29分。
数据库已经累计物理读6285630462块,但查看累计值没有意义。如果要查看8月10日上午8点30分到9点的物理读,可以很简单地扩展如上语句为如下语句:
selecta.BEGIN_INTERVAL_TIME,
b.BEGIN_INTERVAL_TIME,
a.value,
b.value,
(b.value-a.value)/1800
from
(selecta.BEGIN_INTERVAL_TIME,
a.SNAP_ID,
b.stat_name,
b.value
from DBA_HIST_SNAPSHOT a,DBA_HIST_SYSSTAT b
wherea.BEGIN_INTERVAL_TIME>=to_date('2011-08-10 08:30:00')
anda.BEGIN_INTERVAL_TIME<=to_date('2011-08-10 08:59:00')
andb.SNAP_ID=a.SNAP_ID and b.stat_name like 'physical reads'
) a,
(selecta.BEGIN_INTERVAL_TIME,
a.SNAP_ID,
b.stat_name,
b.value
from DBA_HIST_SNAPSHOT a,DBA_HIST_SYSSTAT b
wherea.BEGIN_INTERVAL_TIME>=to_date('2011-08-10 09:00:00')
anda.BEGIN_INTERVAL_TIME<=to_date('2011-08-10 09:29:00')
andb.SNAP_ID=a.SNAP_ID and b.stat_name like 'physical reads'
) b;
BEGIN_INTERVAL_TIMEBEGIN_INTERVAL_TIMEVALUE VALUE(B.VALUE-A.VALUE)/1800
-------------------------------------------------- ---------- ------------ ------
10-AUG-11 08.30.52.268 AM 10-AUG-11 09.00.53.960 AM 6274864874 6285630462 5980.88222
因为快照间隔时间是半个小时,共1800秒,因此在SQL语句中有(b.value-a.value)/1800,总半个小时的总量除以1800秒,得到8月10日8点30分到9点,物理读每秒约5980块。
除SNAP_ID列以外,有些视图也有时间列,像DBA_HIST_UNDOSTAT、DBA_HIST_ACTIVE_SESS_HISTORY等。它们的值并不累加,不像DBA_HIST_SYSSTAT、DBA_HIST_FILESTATXS等这些资料的视图,它们的值是累加的。而DBA_HIST_ACTIVE_SESS_HISTORY类型的视图和前面所述又不一样,在一个快照周期(比如30分钟)内,可以有各种各样的等待事件。对于这样的情况,Oracle在一个AWR快照周期内,又会以固定的间隔时间抓取此类视图的快照。就以DBA_HIST_ACTIVE_SESS_HISTORY为例,Oracle每秒将V$Session快照写入V$ACTIVE_SESSION_HISTORY,每10秒写入DBA_HIST_ACTIVE_SESS_HISTORY。因此,这类视图除了有一个SNAP_ID外,还会有个SAMPLE_ID列。SNAP_ID是AWR快照ID,SAMPLE_ID则是此类视图自己的快照ID。
此类视图的查看不需要将两份快照的值相减,以半小一次AWR快照为例,8点30分到9点的等待事件,在DBA_HIST_ACTIVE_SESS_HISTORY中SNAP_ID统一取8点30分的值。因此,查看8月10日8点30分到9点的等待事件的语句如下:
setlinesize 1000
col BEGIN_INTERVAL_TIME for a40
selecta.BEGIN_INTERVAL_TIME,
a.SNAP_ID,
b.SAMPLE_TIME,
b.event,
b.p1,
b.p2
from DBA_HIST_SNAPSHOT a,DBA_HIST_ACTIVE_SESS_HISTORY b
wherea.BEGIN_INTERVAL_TIME>=to_date('2011-08-10 08:30:00')
anda.BEGIN_INTERVAL_TIME<=to_date('2011-08-10 08:59:00')
andb.SNAP_ID=a.SNAP_ID
andb.wait_class<> 'Idle'
order by sample_time;
当然,也可以不管什么SNAP_ID了,因为此类视图自带时间,直接以时间为单位查询也可以。
select SNAP_ID,
SAMPLE_ID,
SAMPLE_TIME,
session_id,
USER_ID,
event,
p3,
module
from DBA_HIST_ACTIVE_SESS_HISTORY
where SAMPLE_TIME>=to_date('2011-08-10 08:30:00','yyyy-mm-dd hh24:mi:ss')
and SAMPLE_TIME<=to_date('2011-08-10 09:00:00','yyyy-mm-dd hh24:mi:ss')
order by sample_time;
如果想查看SQL会麻烦一些。
setlinesize 1000
col BEGIN_INTERVAL_TIME for a40
selecta.BEGIN_INTERVAL_TIME,
a.SNAP_ID,
b.sql_id,
b.EXECUTIONS_TOTAL,
b.EXECUTIONS_DELTA,
DISK_READS_TOTAL,
DISK_READS_DELTA
from DBA_HIST_SNAPSHOT a,DBA_HIST_SQLSTAT b
wherea.BEGIN_INTERVAL_TIME>=to_date('2011-08-10 08:30:00')
anda.BEGIN_INTERVAL_TIME<=to_date('2011-08-10 08:59:00')
andb.SNAP_ID=a.SNAP_ID ;
select * from
(
selecta.BEGIN_INTERVAL_TIME,
a.SNAP_ID,
b.sql_id,
b.EXECUTIONS_TOTAL,
b.EXECUTIONS_DELTA,
DISK_READS_TOTAL,
DISK_READS_DELTA
from DBA_HIST_SNAPSHOT a,DBA_HIST_SQLSTAT b
wherea.BEGIN_INTERVAL_TIME>=to_date('2011-08-10 09:00:00')
anda.BEGIN_INTERVAL_TIME<=to_date('2011-08-10 09:29:00')
andb.SNAP_ID=a.SNAP_ID
)
wheresql_id='aqb23gd02krbd';
在SQL的AWR视图中,有关资料的列通常有两列:***_TOTAL,***_DELTA。以物理读为例,DISK_READS_TOTAL表示累计物理读,DISK_READS_DELTA表示两次AWR快照的物理读增量值。如果半小时抓一次AWR快照,那么9点时候的DISK_READS_DELTA中保存的是8点30分到9点间某条SQL的物理读。
以下语句查看8月10日8点30分到9点间SQL的物理读和执行次数,以增量物理读排序(注意,8点30分到9点间的增量数据,在9点的快照中)。
setlinesize 1000
col BEGIN_INTERVAL_TIME for a40
selecta.BEGIN_INTERVAL_TIME,
a.SNAP_ID,
b.sql_id,
b.EXECUTIONS_TOTAL,
b.EXECUTIONS_DELTA,
DISK_READS_TOTAL,
DISK_READS_DELTA
from DBA_HIST_SNAPSHOT a,DBA_HIST_SQLSTAT b
wherea.BEGIN_INTERVAL_TIME>=to_date('2011-08-10 09:00:00')
anda.BEGIN_INTERVAL_TIME<=to_date('2011-08-10 09:29:00')
andb.SNAP_ID=a.SNAP_ID
order by DISK_READS_DELTA;
查询结果如下:
BEGIN_INTERVAL_TIME SNAP_ID SQL_ID EXECUTIONS_TOTAL EXECUTIONS_DELTA DISK_READS_TOTAL DISK_READS_DELTA
--------------------------------------- ---------- ------------- ----------------
10-AUG-11 09.00.53.960 AM 26816 cqda35pgjhxc4 1 1 2743922 495307
10-AUG-11 09.00.53.960 AM 26816 c3amcasx93pvb 190 1 82661833 500732
10-AUG-11 09.00.53.960 AM 26816 4qk3ay7bq4pab 1250 1 571678928 508307
10-AUG-11 09.00.53.960 AM 26816 2skr3f87yx371 0 0 1648390 1648390
10-AUG-11 09.00.53.960 AM 26816 7d36vg5ntu4x4 1 1 1651535 1651535
10-AUG-11 09.00.53.960 AM 26816 b2q33zan1bk40 1 1 2239386 2239386
10-AUG-11 09.00.53.960 AM 26816 3u19w33vtv358 1 1 4043676 2473630
DBA_HIST_SQLSTAT中没有SQL语句,要查看SQL语句,还要和DBA_HIST_SQLTEXT关联。此视图中没有时间、SNAP_ID这些列,只有SQL_ID列。以上面的查询结果为例,查看物理读最多的SQL是哪条的语句如下:
selectDBID,SQL_ID,SQL_TEXT from DBA_HIST_SQLTEXT where sql_id='3u19w33vtv358';
DBID SQL_ID SQL_TEXT
---------- ----------------------------------------
978291946 3u19w33vtv358 insert /*+append*/ into
***.*******
select * from *****.en_
这是条同步语句。
另外,在DBA_HIST_SQL_PLAN中,还有历史执行计划,此视图也是只有SQL_ID列,没有时间和快照ID列。
另外,还有一个视图必须交代一下,即ASH(ActiveSessionHistory)。从名字就可以知道,这些视图着重反映数据库的“历史”情况,对于诊断数据库的“历史”问题很有帮助。通常从发现数据库有问题,到DBA登录到数据库查看情况中间,至少会有十几分钟的时间,有可能DBA登录数据库查看时,问题已经没有了。通过ASH类历史视图,可以查看几分钟前,甚至几个小时、几天前的等待事件等信息,从而帮助DBA诊断问题是如何产生的。
ASH对应的视图就是V$ACTIVE_SESSION_HISTORY,Oracle每秒会将所有会话非Idle类的等待事件记录到此视图中。此视图的所有数据都在内存中,Oracle会定期将数据写到DBA_HIST_ACTIVE_SESS_HISTORY中,此数据字典视图存储在磁盘中。