理论实践:循序渐进理解AWR细致入微分析性能报告

理论实践:循序渐进理解AWR细致入微分析性能报告

 

黄凯耀 (Kaya) ACOUG核心会员,高级技术专家

曾经工作于Oracle Real World Database Performance Group,一个隶属于Oracle公司总部数据库产品管理的核心团队。大学及研究生时期专注于Linux应用开发和Linux内核开发工作。

编辑手记:AWR是Oracle数据库中一个非常重要的诊断工具,通过度量而展现问题,每一个DBA都应当深入理解这其中的知识,本文通过讲解和分析,展示AWR分析的过程。

概述:本篇文章重点对 AWR 报告中的 DB Time、DBCPU、IO 等数据进行了说明,可帮助读者更加清楚的理解这些数据代表的含义,与数据库的性能表现有何关系。同时通过两个简短的例子,实践如何分析 AWR 报告。

1. AWR 概述

Automatic Workload Repository(AWR) 是10g引入的一个重要组件。在里面存贮着近期一段时间内(默认是7天)数据库活动状态的详细信息。

AWR 报告是对 AWR 视图进行查询而得到的一份自动生成的报告。可以通过下面的脚本手工得到一份 AWR 报告。

wps6881.tmp

通过 AWR 和 AWR 报告,DBA 可以容易地获知最近数据库的活动状态,数据库的各种性能指标的变化趋势曲线,最近数据库可能存在的异常,分析数据库可能存在的性能瓶颈从而对数据库进行优化。

AWR 报告所有的数据来源于 AWR 视图,即以 DBA_HIST_开头的所有系统表,Database Reference 有对所有这些系统表的描述,这应该是 Oracle 官方对 AWR 报告的官方注释了。而对于如何有效地去分析 AWR 报告,这可能更需要 DBA 经验的日积月累。

AWR的前身是Statspack,Statspack在10g和11g中也有提供,同时和AWR一起做了同步更新,而且Statspack是公开源代码的,因此,关于Statspack的资料,还有Statspack的源代码,都是理解AWR的一个有用的辅助。

本文着重对AWR中的一些要点进行剖析,欢迎一起讨论AWR相关的问题。

2. DB CPU - CPU负载分析

如果关注数据库的性能,那么当拿到一份 AWR 报告的时候,最想知道的第一件事情可能就是系统资源的利用情况了,而首当其冲的,就是 CPU。

而细分起来,CPU 可能指的是:

OS 级的 User%,Sys%, Idle%

DB 所占 OS CPU 资源的 Busy%

DBCPU 又可以分为前台所消耗的 CPU 和后台所消耗的 CPU

如果数据库的版本是11g,那么很幸运的,这些信息在AWR报告中一目了然:

wps6882.tmp

wps6883.tmp

分析上面的图片,我们可以得出下面的结论:

OS 级的 User%,Sys%,Idle%:

OS 级的 %User 为75.4,%Sys 为2.8,%Idle 为21.2,所以 %Busy 应该是 100-21.1=78.8。

DB所占OSCPU资源的Busy%

DB占了OS CPU资源的69.1,%Busy CPU则可以通过上面的数据得到:

%Busy CPU = %Total CPU/(%Busy) * 100 = 69.1/78.8 * 100 = 87.69,和报告的87.7相吻合。

如果是10g呢,则需要手工对 Report 里的一些数据进行计算了。

Host CPU 的结果来源于 DBA_HIST_OSSTAT,AWR 报告里已经帮忙整出了这段时间内的绝对数据(这里的时间单位是centi second,也就是1/100秒)

wps68A4.tmp

根据上面的数据,稍加计算分析便可得出下面的结果。

OS级的User%,Sys%,Idle%:

%User = USER_TIME/ (BUSY_TIME+IDLE_TIME)*100 =146355/ (152946+41230)*100 = 75.37

%Sys = SYS_TIME/ (BUSY_TIME+IDLE_TIME)*100=5462/(152946+41230)*100=2.81

%Idle = IDLE_TIME/ (BUSY_TIME+IDLE_TIME)*100=21230/(152946+41230)*100=10.93

值得注意的,这里已经隐含着这个AWR报告所捕捉的两个Snapshot之间的时间长短了。有下面的公式:

BUSY_TIME + IDLE_TIME = ELAPSED_TIME * CPU_COUNT

注意:正确的理解这个公式可以对系统CPU资源的使用及其度量的方式有更深一步的理解。

因此ELAPSED_TIME =(152946+41230)/8/100 = 242.72 seconds

至于DB对CPU的利用情况,这就涉及到10g新引入的一个关于时间统计的视图V$SYS_TIME_MODEL,简单而言,Oracle采用了一个统一的时间模型对一些重要的时间指标进行了记录,具体而言,这些指标包括:

1) Background elapsed time

2) Background CPU time

3) RMAN CPU time (backup/restore)

1) DB time

2) DB CPU

2) Connection management call elapsed time

2) Sequence load elapsed time

2) SQL execute elapsed time

2) Parse time elapsed

3) Hard parse elapsed time

4) Hard parse (sharingcriteria) elapsed time

5) Hard parse (bindmismatch) elapsed time

3) Failed parse elapsed time

4) Failed parse (out of sharedmemory) elapsed time

2) PL/SQL execution elapsed time

2) Inbound PL/SQL RPC elapsed time

2) PL/SQL compilation elapsed time

2) Java execution elapsed time

2) Repeated bind elapsed time

这里我们关注的只有和 CPU 相关的两个: Background CPU time 和 DB CPU。

这两个值在 AWR 里面也有记录:

wps68B4.tmp

Total DB CPU = DB CPU + Background CPUtime = 1305.89 + 35.91 = 1341.8 seconds

Total DB CPU除以总的 BUSY_TIME + IDLE_TIME可得出% Total CPU。

% Total CPU = 1341.8/1941.76 = 69.1%,这刚好与上面Report的值相吻合。

其实,在 Load Profile 部分,我们也可以看出DB对系统CPU的资源利用情况。

wps68C5.tmp

用 DBCPU per Second 除以 CPU Count 就可以得到 DB 在前台所消耗的 CPU% 了。这里 5.3/8 = 66.25 %比69.1%稍小,说明DB在后台也消耗了大约3%的 CPU,这是不是一个最简单的方法了呢?

3. DB Time – 进程消耗时间分析

DB CPU 是一个用于衡量 CPU 的使用率的重要指标。假设系统有N个 CPU,那么如果 CPU全部处于繁忙状态的话,一秒钟内的 DBCPU 就是N秒。

如何去表征一个系统的繁忙程度呢?除了利用 CPU 进行计算外,数据库还会利用其它计算资源,如网络、硬盘、内存等等,这些对资源的利用同样可以利用时间进行度量。假设系统有M个 Session 在运行,同一时刻,有的 Session 可能在利用 CPU,有的 Session 可能在访问硬盘,那么,在一秒钟内,所有 Session 的时间加起来就可以表征系统在这一秒内的繁忙程度,一般的,这个和的最大值应该为 M。这其实就是 Oracle 提供的另一个重要指标:DB Time,它用以衡量前端进程所消耗的总时间。

对除 CPU 以外的计算资源的访问,Oracle 用等待事件进行描述。同样地,和 CPU 可分为前台消耗 CPU 和后台消耗 CPU一样,等待事件也可以分为前台等待事件和后台等待事件。

DB Time 一般的应该等于DB CPU + 前台等待事件所消耗时间的总和。等待时间通过 V$SYSTEM_EVENT 视图进行统计,DB Time 和 DBCPU 则是通过同一个视图,即V$SYS_TIME_MODEL 进行统计。

Load Profile 一节就有了对 DB Time 的描述:

wps68C6.tmp

这个系统的 CPU 个数是8,因此我们可以知道前台进程用了系统 CPU 的7.1/8=88.75%。 DB Time/s 为11.7,可以看出这个系统是 CPU 非常繁忙的。里面 CPU 占了7.1,则其它前台等待事件占了11.7 –7.1 = 4.6 Wait Time/s。DB CPU 占 DB Time 的比重呢? 7.1/11.7= 60.68%

Top 5 Timed Events,或许很多人都对它有所耳闻,按照 CPU/ 等待事件占 DB Time 的比例大小,这里列出了 Top 5。如果一个工作负载是 CPU 繁忙型的话,那么在这里应该可以看到 DB CPU 的影子。

wps68C7.tmp

注意到,我们刚刚已经算出了 DB CPU 的 %DB time 为60%左右。

其它的 externaltable read,direct path write, PX Deq: read credit, PXDeq: Slave Session Stats 这些就是占比重40%的等待事件里的 Top 4了。

回过头再研究下这个 Top 5 Timed Foreground Events,如果先不看 Load Profile,你能说出这个一个 CPU-Bound 的工作负载吗?

答案是否定的,要知道系统 CPU 的繁忙程序,还要知道这个 AWR 所基于两个 Snapshot 的时间间隔,还要知道系统 CPU 的个数。否则,系统可以是一个很 IDLE 的系统呢。记住 CPU 利用率= DB CPU/(CPU_COUNT*Elapsed TIME)。

这个 Top5 给我们的信息只是这个工作负载应该是并行查询,从外部表读取数据,并用 insert append 的方式写入磁盘,同时,主要时间耗费在 CPU 的运算上。

上面提到,DB Time 一般的应该等于 DB CPU + 前台等待事件所消耗时间的总和。在下面有对这三个值的统计:

wps68D7.tmp

DB CPU = 6474.65

DB TIME = 10711.2

FG Wait Time = 1182.63

明显的,DBCPU + FG Wait Time < DB Time,只占了71.5%

其它的28.5%被消耗到哪里去了呢?这里其实又隐含着一个 Oracle 如何计算 DBCPU 和 DB Time 的问题。当 CPU 很忙时,如果系统里存在着很多进程,就会发生进程排队等待 CPU 的现象。在这样,DB TIME 是把进程排队等待 CPU 的时间算在内的,而 DB CPU 是不包括这一部分时间。这是造成 DB CPU + FG Wait Time < DB Time 的一个重要原因。如果一个系统 CPU 不忙,这两者应该就比较接近了。

不要忘了在这个例子中,这是一个 CPU 非常繁忙的系统,而71.5%就是一个信号,它提示着这个系统可能是一个 CPU-Bound 的系统。

4. IO数据分析

除了 DBCPU、DB Time,或许另一个比较常用的指标应该是 IO 的利用情况。关于 IO 的指标就比较多了,单单在 Load Profile 里面就有5个,在 DBTime 和 DB CPU 的下面:

wps68E8.tmp

这5个指标的值都来自 V$SYSTAT 视图,分别是:

Redo Size: ‘redo size’

Logical reads = ’session logical reads’or (’db block gets’ + ‘consistent gets’)

Blocks Changes = ‘db block changes’

Physical reads = ‘physical reads’

Physical writes = ‘physical writes’

具体指标的解释可以参考Database Reference(http://docs.oracle.com/cd/B28359_01/server.111/b28320/stats002.htm)

如何得到系统大致的 MBPS(Megabits Per Second) 呢?

MBPS= (Physical reads + Physical writes) *Block_Size = (196,271.4+2.0)*8*1024/1024/1024 = 1533 MB/s

更准确的 MBPS 可以从 Instance Activity Stats 部分获得。

wps68F9.tmp

Physical IO disk bytes = physical read total bytes+ physical write total bytes

值得注意的是这里 physical write total bytes 大致是 physical writebytes 的两倍。这应该是 physical write total bytes 统计的是磁盘的 IO,而这里,我们做了 ASM,normal redundancy,一份数据写了两遍的原因。

Load Profile 剩下的部分主要是关于各种执行情况的统计,除了 W/A MB processed 来自 V$PGASTAT(单位其实也是 Byte,不是 MB),其它数据都是来自于 V$SYSSTAT。

Blocks Changes: ‘db block changes’

User calls: ‘user calls’

Parses: ‘parse count (total)’

Hard parses: ‘parse count (hard)’

Logons: ‘logons cumulative’

Executes: ‘execute count’

Rollbacks: ‘user rollbacks’

Tranasactions: ‘user rollbacks’ + ‘usercommits’

W/A MB processed: ‘bytes processed’

一般而言,Hard parses < Parses < Executes < User Calls。

AWR 的一般性介绍我想差不多就这些了,其它部分的介绍借助于一些更具体的 AWR 报告进行分析可能会更加方便和清晰。

5. AWR 报告分析 – 实战1

构建 DSS 系统的第一步离不开数据加载,通过文本文件加载是最常见的方式,Oracle 提供了外部表加载的方法,即把一个文本文件当成一个正常的表来进行操作,通过类似 insert /*+ append */ into table select from external_table 的方式进行加载。

数据加载是一个 CPU-Bound 的过程,不过是通过什么工具,external table 也好,sqlldr 也好,imp 也好,impdp 也好。换句话说,如果连数据加载都出现 IO 瓶颈,这个系统的配置就说不过去了。

这个过程的 AWR 报告会是什么样子的呢?

先做个一般的假定,从外部表加载数据到一个本地分区表。

Top 5 TimedEvents 类似下面:

wps6909.tmp

如果去抓取这段时间 DBA_HIST_ACTIVE_SESS_HISTORY 的数据,并转换为图表的话,我们会得到更形象的 Top 10 Wait Events。(如何实现这一步可以参考用 Oracle 实现 ASH 的数据透视图:http://www.cnblogs.com/rootq/archive/2009/09/24/1573200.html)

wps690A.tmp

enq: HV –contention 是什么东西呢?

在11.2以前,对于分区表的 parallel direct-path load,Oracle 采用的是 brokered load 的方式,即所有的 PX Slaves 共享对每个分区的 high water mark 的访问,通过轮流持有 high water mark 实现对每个 segment 添加新的 blocks。这种方法对于充分利用 extent 的空间是有帮助的,不过带来的问题就是对 high water mark 的竞争,也就是这里的 enq: HV – contention。在执行计划中,这以 RANDOM LOCAL 标记。下面是一个例子:

wps691B.tmp

一个好消息是,11.2引入了一种新的方式,叫做 PKEY distribution。在这种方式下,一个特定的分区只交给一个或多个特定的 PX slave 负责,这种方式不仅减少了对 high water mark 的争用,而且可以实现 Partition 内更好的压缩率。

6. AWR报告分析 – 实战2

有一次跟一个 QQ 上的朋友一起探讨了另一个对系统 CPU 进行度量的指标: CPUused by this session。

他刚好有一份 AWR 报告,在这份报告里,出现了严重的 CPU used by this session 和 DB CPU 不一致的现象。

下面是这份报告的一些片断:

wps692C.tmp

wps692D.tmp

wps693D.tmp

wps693E.tmp

再做进一步的归纳:

OS Busy% =1821080/(1821080+5384293) = 25%

Inst CPU% (usingDB CPU) = 8934.22*100/ (1821080+5384293)=12%

Inst CPU% (usingCPU used by this session) = 418035/ (1821080+5384293) = 6%

用 CPU used by this session 计算出的 CPU 利用率竟然只是用 DB CPU 计算出来的利用通率的一半!

我的第一个反应是在 Jonathan Lewis 网站看到的一篇相关文章,里面提到了 DB CPU 和 CPUused by this session 计算时的不同之处:(https://jonathanlewis.wordpress.com/2009/05/26/cpu-used/)

“Prior to10g Oracle usually updated time figures at the end of each database call; butfrom 10g there are some views where time is updated more regularly.

The “DB CPU” from v$sess_time_model increases every six seconds, while the “CPU used by this session” from v$sesstat changes only at the end of the test.”

如何验证这一点呢?

在浏览这份报告的 TOP SQL 时,我们发现了下面的现象:

wps693F.tmp

这是从 SQL ordered by Elapsed Time 截取出来的 Top 3 SQL。TOP 1 的 SQL 用了 DB Time 的30.10%,用了2517s 的 CPU Time。但请注意它的 Executions 的值却为0。也就是说,这里的 CPU Time 是还没有被计算入 CPU used by this session 这个指标里面的。

我们再把2517s加回来,看出误差缩小多少:

(251700+418035)/(1821080+5384293) = 9%

这时和用 DB CPU 计算出来的12%还是有1/4的差距。

从这个例子可以看出,用 DB CPU 度量还是比用 CPU usedby this session 来得准确的。特别在有大查询在跑的过程中抓的 AWR,这个误差很有可能会被放大。这是一个有趣的实际例子。

7. 总结

AWR 是分析数据库运行状况的利器,将其运用好可帮助 DBA 提早发现数据库中存在的问题并加以解决。文中主要对 DB CPU、DB Time、IO 等 AWR 报告中的数据进行了分析说明,当然分析AWR报告不能仅限于此,更需要DBA日积月累的经验。希望本文对想了解 AWR 的朋友有一定帮助。

About Me

 

.........................................................................................................................................................................................................

本文来自于微信公众号转载文章,若有侵权,请联系小麦苗及时删除

本文在ITpub(http://blog.itpub.net/26736162)和博客园(http://www.cnblogs.com/lhrbest)有同步更新

联系我请加QQ好友(642808185),注明添加缘由

【版权所有,文章允许转载,但须以链接方式注明源地址,否则追究法律责任】

.........................................................................................................................................................................................................

 

posted @ 2016-06-17 19:13  DB宝  阅读(1613)  评论(0编辑  收藏  举报