使用awr来诊断数据库性能问题

awr报告是一种极其有效的诊断工具来确定潜在的导致数据库性能问题的原因.

通常当性能问题被检查到时你可以在出现性能问题期间收集一个awr报告.收集awr报告的期间最好不要超过一个小时否则有可能会丢失一些细节.

当数据库性能在可接受期间也可以收集awr报告来作为基线当出现数据库性能问题是可以用来进行比较.要确保性能基线收集的时间与出现性能问题时收集awr的时间相同这样才有可比性.

当我们正在查找性能问题是我们的主要关注点在数据库正在等待什么.当进程等待时它们会被阻止做任何操作.

top等待事件提供了对于问题来说需要我们关注的信息而不用浪费时间去调查其它的原因.

top 5时间事件
注意top等待部分是整个awr报告中的最重要的一个部分它可以用来量化性能和进行诊断比较

Top 5 Timed Events Avg %Total
~~~~~~~~~~~~~~~~~~ wait Call
Event Waits Time (s) (ms) Time Wait Class
—————————— ———— ———– —— —— ———-
db file scattered read 10,152,564 81,327 8 29.6 User I/O
db file sequential read 10,327,231 75,878 7 27.6 User I/O
CPU time 56,207 20.5
read by other session 4,397,330 33,455 8 12.2 User I/O
PX Deq Credit: send blkd 31,398 26,576 846 9.7 Other
————————————————————-

top 5等待部分报告了一系列有用的相关等待事件.它记录了在遇到性能期间所发生的等待次数和等待总的时间以及每个事件的平均等待时间.

在上面的这个例子中,几乎60%的等待时间是与IO相关的读取操作
事件’db file scattered read’是典型用于全表扫描和索引快速完全扫描时执行多块读相关的等待事件
事件’db file sequential read’是用于块读和通常用于不能执行多块读时相关的等待事件(例如索引读取)

另外的20%的等待时间划CPU time.高cpu利用率通常是低性能sql(执行昂贵的IO操作)的一个标识符(或者sql语句有使用更少资源的潜能)

基于以上的信息我们将会调查这些等待是否指示了性能问题.如果是解决这些问题,如果不是继续查看下一部分信息是否是造成性能问题的原因

有两个原因让IO相关的等待事件成为top等待事件
1.数据库正在执行大量的读取操作
2.单个读取操作很慢

top5等待事件有以下帮助:
1.数据库正在执行大量的读取操作?
这部分信息显示了在这个awr报告期间这些等待事件中每一个执行了1000万次读取,这个读取次数是否是大量读取操作取决于awr报告的持续时间是1小时还是1分钟.检查报告期间来评估这个问题.如果读取操作过度那么为什么数据库还会执行大量的读取操作?数据库只读取数据是因为执行的sql语句指示它进行读取操作为了调整可以查看sql statistics部分的信息.

2.是不是单个读取操作慢?
这部分显示了两个等待<=8ms的IO相关等待事件,这个是快是慢取于硬件底层的IO子系统,但通常低于20ms是可以接受

如果IO慢,那么可以从’Tablespace IO stats’部分得到以下信息:

Tablespace IO Stats DB/Inst: VMWREP/VMWREP Snaps: 1-15
-> ordered by IOs (Reads + Writes) desc

Tablespace
——————————
Av Av Av Av Buffer Av Buf
Reads Reads/s Rd(ms) Blks/Rd Writes Writes/s Waits Wt(ms)
————– ——- —— ——- ———— ——– ———- ——
TS_TX_DATA
14,246,367 283 7.6 4.6 145,263,880 2,883 3,844,161 8.3
USER
204,834 4 10.7 1.0 17,849,021 354 15,249 9.8
UNDOTS1
19,725 0 3.0 1.0 10,064,086 200 1,964 4.9
AE_TS
4,287,567 85 5.4 6.7 932 0 465,793 3.7
TEMP
2,022,883 40 0.0 5.8 878,049 17 0 0.0
UNDOTS3
1,310,493 26 4.6 1.0 941,675 19 43 0.0
TS_TX_IDX
1,884,478 37 7.3 1.0 23,695 0 73,703 8.3
SYSAUX
346,094 7 5.6 3.9 112,744 2 0 0.0
SYSTEM
101,771 2 7.9 3.5 25,098 0 653 2.7

特别注意的是查看RD(ms)的值,如果每次读取时间的值高于20ms,那么你可以从操作系统层开始调查IO屏颈.注意:你应该忽略相关的空闲的表空间/文件当你发现RD(ms)的值较高时可能是因为磁盘的spinup造成的这与性能无关.如果你读取1000万次读取被认为是IO慢这不太可能它可能是表空间/文件只有10个读取操作造成的问题

虽然高等待’db file scattered read’和’db file sequential read’事件可能与IO相关,但是实际上发现大部分这些等待事件基于数据库正在运行的sql语句来说是正常的.实际上,在一个高度优化的数据中,希望它们出现在top等待事件中,因此这意味着数据库没有性能问题.

它们被用来评估是否高等待说明了某些sql语句没有使用最佳的访问路径.如果有大量的’db file scattered read’等待事件,那么sql可能没有使用最佳的访问路径因此使用了全表扫描而不是索引扫描(或者可能是丢失索引或者没有最佳的索引可用).此外,大量的’db file sequential read’等待事件可以说明了sql语句正在使用非选择性索引且因此要读取更多的索引块或者使用了错误的索引.因此这些等待事件可能说明sql语句执行计划性能较低.

不管怎样,都应该从awr报告中检查top资源消耗的情况来判断它们是否过度或是否可以改进

注意上面有20%的等待时间是cpu时间.在查看sql统计时也应该被检查.后面的检查是依据tops等待进行的.例如在上面的top5等待事件中前功尽弃3个是指示有性能不佳的sql语句应该进行调查

同样的如果你没有看到latch等待那么latch就不是造成性能问题的原因所以就不需要继续调查latch等待.

一般来说,如果数据库慢那么top5等待事件中包含”cpu”和”db file sequential read”和”db file scattered read”那么这说明将要注意查看top sql(通过逻辑和物理读取分类的)部分和叫做sql调整指导(或手动调整它们)来确保
它们有效的运行.

SQL Statistics
SQL ordered by Elapsed Time
SQL ordered by CPU Time
SQL ordered by User I/O Wait Time
SQL ordered by Gets
SQL ordered by Reads
SQL ordered by Physical Reads(UnOptimized)
SQL ordered by Executions
SQL ordered by Parse Calls
SQL ordered by Sharable Memory
SQL ordered by Version Count
SQL ordered by Cluster Wait Time
Complete List of SQL Text
上面不同的sql统计信息应该根据top5等待事件中的不同等待事件进行查看.例如在我们的例子中,我们看到有’db file scattered read’,’db file sequential read’和cpu.对于这些我们要重点关注SQL ordered by CPU Time,SQL ordered by Gets和SQL ordered by Reads部分.

通常查看’SQL ordered by gets’部分指示sql语句有较高的缓存获取通常需要进行合适的调优:

SQL ordered by Gets
-> Resources reported for PL/SQL code includes the resources used by all SQL
statements called by the code.
-> Total Buffer Gets: 4,745,943,815
-> Captured SQL account for 122.2% of Total

Gets CPU Elapsed
Buffer Gets Executions per Exec %Total Time (s) Time (s) SQL Id
————– ———— ———— —— ——– ——— ————-
1,228,753,877 168 7,314,011.2 25.9 8022.46 8404.73 5t1y1nvmwp2
SELECT ADDRESSID”,CURRENT$.”ADDRESSTYPEID”,CURRENT$URRENT$.”ADDRESS3″,
CURRENT$.”CITY”,CURRENT$.”ZIP”,CURRENT$.”STATE”,CURRENT$.”PHONECOUNTRYCODE”,
CURRENT$.”PHONENUMBER”,CURRENT$.”PHONEEXTENSION”,CURRENT$.”FAXCOU

1,039,875,759 62,959,363 16.5 21.9 5320.27 5618.96 grr4mg7ms81
Module: DBMS_SCHEDULER
INSERT INTO “ADDRESS_RDONLY” (“ADDRESSID”,”ADDRESSTYPEID”,”CUSTOMERID”,”
ADDRESS1″,”ADDRESS2″,”ADDRESS3″,”CITY”,”ZIP”,”STATE”,”PHONECOUNTRYCODE”,”PHONENU

854,035,223 168 5,083,543.0 18.0 5713.50 7458.95 4at7cbx8hnz
SELECT “CUSTOMERID”,CURRENT$.”ISACTIVE”,CURRENT$.”FIRSTNAME”,CURRENT$.”LASTNAME”,CU<
RRENT$.”ORGANIZATION”,CURRENT$.”DATEREGISTERED”,CURRENT$.”CUSTOMERSTATUSID”,CURR
ENT$.”LASTMODIFIEDDATE”,CURRENT$.”SOURCE”,CURRENT$.”EMPLOYEEDEPT”,CURRENT$.

调整可以手动进行也可以通过sql调整指导来进行

对上面的信息进行分析:
Total Buffer Gets: 4,745,943,815
我们假设这是一个时间间隔为1小时的awr报告,这是对于buffer get来说是一个重要的数字因此这证实了为了确保它们正使用最佳的访问路么它们是值得调查的top sql语句.

单个 buffer gets
对于单个语句的buffer gets是非常高得最小的也有854,035,223次.这三个语句实际上指出了有大量buffer gets的两大原因:
过度的buffer gets/exectuion sql_id ‘5t1y1nvmwp2’和’4at7cbx8hnz’仅仅只执行了168次,但每一次执行读取超过500万的buffer.这个语句是要被进行调优的主要对象因为buffer在太高了.

过度的执行
另一方面sql_id ‘grr4mg7ms81’每次执行只读取16个buffer.调整这个语句不能有效的减少buffer 读.然而这个问题可能是由这个语句的执行次数造成的—执行62,959,363次.改变这个语句的调用方式–它很可能在一个循环中一次获取一行记录,可以修改成一次执行获取多条记录那么这样就会有效的减少buffer读取.

记住这些数字对于繁忙的工作环境可能是正常的.可通通过使用这个时间的awr报告与性能基线awr报告进行比较,你可以看看这些语句在数据库性能良好的情况下是不是也执行了这么多的buffer读取.如果也是那么就不用关注这个问题了可以忽略它们(因为改进这些语句可以提高一些性能)

其它的sql统计信息部分
在sql统计信息部分有不同的报告部分用于指示不同的原因,如果你没有特定问题那么查看这部分信息的作用有限.
Waits for ‘Cursor: mutex/pin’
如果在这有mutex等待象”Cursor:pin S wait on X’ or ‘Cursor:mutex X’,这些象征着解析问题.
最基本的就是查看有高解析次数’SQL ordered by Parse Cllas’ 或高版本次数的sql语句 ‘SQL ordered by Version Count’
这是最有可能造成问题的原因.

Load Profile 负载概要
根据等待事件,负载概要部分也提供有用的后台信息或与问题相关的特定信息

Load Profile
~~~~~~~~~~~~ Per Second Per Transaction
————— —————
Redo size: 4,585,414.80 3,165,883.14
Logical reads: 94,185.63 65,028.07
Block changes: 40,028.57 27,636.71
Physical reads: 2,206.12 1,523.16
Physical writes: 3,939.97 2,720.25
User calls: 50.08 34.58
Parses: 26.96 18.61
Hard parses: 1.49 1.03
Sorts: 18.36 12.68
Logons: 0.13 0.09
Executes: 4,925.89 3,400.96
Transactions: 1.45

% Blocks changed per Read: 42.50 Recursive Call %: 99.19
Rollback per transaction %: 59.69 Rows per Sort: 1922.64

在这个例子中,等待事件部分显示的问题是sql语句执行的问题所以负载概要也能检查出相关的信息.

如果你正在为了通常的调整在看awr报告,你可以查看负载部分来显示相关的有高物理写的高重做活动.在上面的信息中写与读的负载比值高达到了43.50%.

此外这里硬解析与软解析比较低.如果在top等待事件中有’library cache:mutex X’,那么整个解析率的统计信息与这些等待事件息息相关

与性能基线awr报告进行比较将提供最好的信息,例如,可以通过比较重做的大小,用户的调用和解析来看负载的改变

Instance Efficiency实例的效率
实例的效率统计信息对于通常的调整来定位特定的问题是很有用的(除非等待事件已经指示出问题的原因)

Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Buffer Nowait %: 99.91 Redo NoWait %: 100.00
Buffer Hit %: 98.14 In-memory Sort %: 99.98
Library Hit %: 99.91 Soft Parse %: 94.48
Execute to Parse %: 99.45 Latch Hit %: 99.97
Parse CPU to Parse Elapsd %: 71.23 % Non-Parse CPU: 99.00

在上面的这个例子中这部分最重要的统计信息是”% Non-Parse CPU”,因为这指示了在top等待事件中几乎所有的CPU时间
都花在了执行操作上而不是解析操作,这意味着调整sql可能提高性能.

如果我们正在调整,那么94.48%的软解析率显示了硬解析率是较小的.这么高的解析率说明很好的使用了共享游标.通常我们希望这个统计值接近100%,但记住有一小部分的百分比不是依赖于应用程序的.例如在一个数据仓库环境中,硬解析可能由于使用了物化视图或直方图变得比较高.所以在出现性能问题时与性能基线awr报告进行比较是很重要的.

Latch Activity 闩锁活动
在这个例子中我们不能看到有效的闩锁等待可以忽略此部分信息.然而,如果闩锁等待很严重那么我们将基于

Latch Sleep Breakdown来查看闩锁等待相关的信息
Latch Sleep Breakdown

* ordered by misses desc

Latch Name
—————————————-
Get Requests Misses Sleeps Spin Gets Sleep1 Sleep2 Sleep3
————– ———– ———– ———- ——– ——– ——–
cache buffers chains
2,881,936,948 3,070,271 41,336 3,031,456 0 0 0
row cache objects
941,375,571 1,215,395 852 1,214,606 0 0 0
object queue header operation
763,607,977 949,376 30,484 919,782 0 0 0
cache buffers lru chain
376,874,990 705,162 3,192 702,090 0 0 0

这里的顶级闩锁是cache buffers chains,cache buffers chains闩锁是用来保护从磁盘读取到缓冲区缓存中的数据.当看到数据正在被读取时这是很正常的闩锁.当这个出现压力时闩锁sleeps数据就会趋向于这些查询请求的等待次数这些竞争可能是由于低效的sql读取相同的buffer造成的.

在上面的例子中虽然buffer gets中的get请求的次数是2,881,936,948但sleeps次数是41,336是较低的.sleeps与misses的平均比率(avg slps/miss)是较低的.原因是服务器能够处理这样规模的数据因此这里对于cache buffers chains闩锁来说没有什么竞争.

cpu等待事件
仅仅因为cpu等待出现在awr报告中的top等待事件中不能说明什么问题.然而如果性能慢且cpu使用率高那么可以调查cpu等待事件,首先可以检查awr报告中的消耗cpu较多的sql语句
SQL ordered by CPU Time
-> Resources reported for PL/SQL code includes the resources used by all SQL
statements called by the code.
-> % Total is the CPU Time divided into the Total CPU Time times 100
-> Total CPU Time (s): 56,207
-> Captured SQL account for 114.6% of Total

CPU Elapsed CPU per % Total
Time (s) Time (s) Executions Exec (s) % Total DB Time SQL Id
———- ———- ———— ———– ——- ——- ————-
20,349 24,884 168 121.12 36.2 9.1 7bbhgqykv3cm9
Module: DBMS_SCHEDULER
DECLARE job BINARY_INTEGER := :job; next_date TIMESTAMP WITH TIME ZONE := :myda
te; broken BOOLEAN := FALSE; job_name VARCHAR2(30) := :job_name; job_subname
VARCHAR2(30) := :job_subname; job_owner VARCHAR2(30) := :job_owner; job_start
TIMESTAMP WITH TIME ZONE := :job_start; job_scheduled_start TIMESTAMP WITH TIME

总的cpu时间:56,207,大概为15分钟.这个信息是否有效依据报告的持续的时间周期.消耗cpu的顶级sql使用了20,349秒大约5分钟占整个数据库时间的9.1%.执行了168次.

发表评论

电子邮件地址不会被公开。