ITPub博客

首页 > 数据库 > Oracle > Statspack(二)

Statspack(二)

原创 Oracle 作者:guyuexue 时间:2007-11-21 09:55:50 0 删除 编辑
第一部分
数据库概要信息

DB Name DB Id Instance Inst Num Release Cluster Host
---------- ----------- ------------ -------- ----------- ------------
GLOB 188430914 glob 1 9.2.0.4.0 NO b02


第二部分
数据库采样时段,这一部分记录了数据库采样的时间,以及采样点数,这部分信息对于report来说是十分重要。

任何统计数据都需要通过时间纬度来衡量,离开了时间,任何数据都失去了意义。

我们在论坛上经常看到有人贴出Top 5等待事件寻求分析,我们的回答是:

无法分析,如果没有时间纬度!

Snap Id Snap Time Sessions Curs/Sess Comment
------- ------------------ -------- --------- -------------------
Begin Snap: 508 10-Nov-03 15:27:29 76 39.4
End Snap: 511 10-Nov-03 15:57:42 66 35.4
Elapsed: 30.22 (mins)

第三部分
主要性能指标说明:

- Execute to Parse %执行分析比率

Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Buffer Nowait %: 100.00 Redo NoWait %: 100.00
Buffer Hit %: 99.81 In-memory Sort %: 100.00
Library Hit %: 98.75 Soft Parse %: 97.05
Execute to Parse %: 44.21 Latch Hit %: 94.79
Parse CPU to Parse Elapsd %: 11.74 % Non-Parse CPU: 96.08


执行分析比率计算公式如下:

100 * (1 - Parses/Executions) = Execute to Parse

所以如果系统Parses > Executions,就可能出现该比率小于0的情况.

该参数计算来自以下部分:

Instance Activity Stats for DB: ORA9 Instance: ora91 Snaps: 30 -32

Statistic Total per Second per Trans
--------------------------------- ------------------ -------------- ------------
exchange deadlocks 481 0.2 0.0
execute count 4,873,158 1,968.2 94.4

……………

parse count (failures) 542 0.2 0.0
parse count (hard) 80,281 32.4 1.6
parse count (total) 2,718,643 1,098.0 52.6
parse time cpu 44,009 17.8 0.9
parse time elapsed 374,902 151.4 7.3

…………………….

通过公式及以上两个数值:

100 * (1 - Parses/Executions) = Execute to Parse

100 * (1 - 2,718,643/4,873,158) = 0.44211884777797067117462 * 100 = 44.21


该值<0通常说明shared pool设置或效率存在问题

造成反复解析,reparse可能较严重,或者可是同snapshot有关

如果该值为负值或者极低,通常说明数据库性能存在问题

Parse CPU to Parse Elapsd %
来自parse time cpu和parse time elapsed

100*(parse time cpu / parse time elapsed)= Parse CPU to Parse Elapsd %

100*(44,009 / 374,902)= 11.7388010733471680599196590% = 11.74%


Rollback per transaction 平均事务回滚率

% Blocks changed per Read: 0.37 Recursive Call %: 1.14
Rollback per transaction %: 38.22 Rows per Sort: 11.83

如果回滚率过高,可能说明你的数据库经历了太多的无效操作
过多的回滚可能还会带来Undo Block的竞争

该参数计算公式如下:

Round(User rollbacks / (user commits + user rollbacks) ,4)* 100%

…………….
user commits 31,910 12.9 0.6
user rollbacks 19,740 8.0 0.4
…………….
对于本例:
Round(19740 / (31910 + 19740),4) = .3822



这一部分的内容还没有写完,在继续进行中...

11.db file scattered read-DB文件分散读取
这种情况通常显示与全表扫描相关的等待。
当数据库进行全表扫时,基于性能的考虑,数据会分散(scattered)读入Buffer Cache。如果这个等待事件比较显著,
可能说明对于某些全表扫描的表,没有创建索引或者没有创建合适的索引,我们可能需要检查这些数据表已确定是否进
行了正确的设置。

然而这个等待事件不一定意味着性能低下,在某些条件下Oracle会主动使用全表扫描来替换索引扫描以提高性能,这
和访问的数据量有关,在CBO下Oracle会进行更为智能的选择,在RBO下Oracle更倾向于使用索引。

因为全表扫描被置于LRU(Least Recently Used,最近最少适用)列表的冷端(cold end),对于频繁访问的较
小的数据表,可以选择把他们Cache到内存中,以避免反复读取。

当这个等待事件比较显著时,可以结合v$session_longops动态性能视图来进行诊断,该视图中记录了长时间(运
行时间超过6秒的)运行的事物,可能很多是全表扫描操作(不管怎样,这部分信息都是值得我们注意的)。

我们通过通过一个案例分析来熟悉一下这个等待事件:



DB Name DB Id Instance Inst Num Release OPS Host
---------- ----------- ---------- -------- ---------- ---- ----------
K2 1999167370 k2 1 8.1.5.0.0 NO k2


这是一个8.1.5的数据库系统,通过脚本增强,我们可以在8.1.5的数据库上使用statspack来进行数据库诊断。

Snap Length
Start Id End Id Start Time End Time (Minutes)
-------- -------- -------------------- -------------------- -----------
170 176 25-Feb-03 10:00:11 25-Feb-03 15:00:05 299.90

Cache Sizes
~~~~~~~~~~~
db_block_buffers: 64000
db_block_size: 8192
log_buffer: 8388608
shared_pool_size: 157286400

………………

Top 5 Wait Events
~~~~~~~~~~~~~~~~~ Wait % Total
Event Waits Time (cs) Wt Time
-------------------------------------------- ------------ ----------------------- -------
db file scattered read 16,842,920 3,490,719 43.32
latch free 844,272 3,270,073 40.58
buffer busy waits 114,421 933,136 11.58
db file sequential read 2,067,910 117,750 1.46
enqueue 464 110,840 1.38
-------------------------------------------------------------

这是一个典型的性能低下的系统,几个重要的等待事件都在Top 5中出现,其中,前3个等待极为显著,需要进行
相应的调整。
在5小时的采样间隔内,其中db file scattered read累计等待时间约10小时,已经成为影响系统性能的主要原因。
了解了这些以后我们就可以进一步察看相关SQL看是否存在可以的SQL语句。

SQL ordered by Gets for DB: K2 Instance: k2 Snaps: 170 - 176

Gets % of
Buffer Gets Executes per Exec Total Hash Value
-------------- ------------ ------------ ------ ------------
SQL statement
------------------------------------------------------------------------------
6,480,163 12 540,013.6 2.4 3791855498
SELECT "PROCESS_REQ"."WORK_ID", "PROCESS_REQ"."STOCK_NO", "PROCESS_R

3,784,566 16 236,535.4 1.4 2932917818
SELECT * FROM FIND_LATER_WO ORDER BY NOTE,ORDER_NO

1,200,976 3 400,325.3 .4 4122791109
SELECT "ITEM_STOCK"."ITEM_NO", "ITEM"."NOTE", "ITEM"

923,944 9 102,660.4 .3 2200071737
SELECT "ITEM_STOCK"."ITEM_NO" , "ITEM_STOCK"."STOCK_NO" ,

921,301 3 307,100.3 .3 2218843294
SELECT "ITEM_STOCK"."ITEM_NO", "ITEM"."NOTE", "ITEM"

911,285 3 303,761.7 .3 1769130587
SELECT "LISTS"."ITEM_NO" , "LISTS"."SUB_ITEM" , "LISTS"

831,439 2 415,719.5 .3 1349577999
SELECT "GROUP_OPER"."ITEM_NO" , "GROUP_OPER"."PROCESS_ID" ,

802,918 1 802,918.0 .3 3613809507
SELECT "LISTS"."ITEM_NO" , "LISTS"."SUB_ITEM" , "ITEM".

800,548 2 400,274.0 .3 2643788247
SELECT "ITEM_STOCK"."ITEM_NO", "ITEM"."NOTE", "ITEM"

666,085 2 333,042.5 .2 3391363608
SELECT "ITEM_STOCK"."ITEM_NO", "ITEM_STOCK"."STOCK_NO",
………..

注意到以上很多查询导致的Buffer Gets都非常庞大,我们非常有理由怀疑索引存在问题,甚至缺少必要的索引。
以上记录的是SQL的片段,通过Hash Value值结合v$sql_text我们可以获得完整的SQL语句。

在这次诊断中,我紧接着去查询的是v$session_longops数据表,一个分组查询的结果如下:

TARGET COUNT(*)
---------------------------------------------------------------- ----------
SA.PPBT_GRAPHOBJTABLE 418
SA.PPBT_PPBTOBJRELATTABLE 53

我们发现这些问题SQL的全表扫描(结合v$session_longops视图中的OPNAME)主要集中在PPBT_GRAPHOBJTABLE和
PPBT_PPBTOBJRELATTABLE两张数据表上。
进一步研究发现这两个数据表上没有任何索引,并且有相当的数据量:

SQL> select count(*) from SA.PPBT_PPBTOBJRELATTABLE;

COUNT(*)
----------
1209017
 SQL> select count(*) from SA.PPBT_GRAPHOBJTABLE;

COUNT(*)
----------
2445

在创建了合适的索引后,系统性能得到了大幅提高!


12.Enqueue
enqueue是一种保护共享资源的锁定机制。该锁定机制保护共享资源,如记录中的数据,以避免两个人在同一时间更新 同一数据。enqueue
包括一个排队机制,即FIFO(先进先出)排队机制。

Enqueue等待常见的有ST、HW 、TX 、TM等

ST enqueue,用于空间管理和字典管理的表空间(DMT)的区间分配,在DMT中典型的是对于uet$和fet$数据字典表的 争用。对于支持LMT的
版本,应该尽量使用本地管理表空间. 或者考虑手工预分配一定数量的区(Extent),减少动态扩展
时发生的严重队列竞争。

我们通过一个实例来看一下:


DB Name DB Id Instance Inst Num Release OPS Host
------------ ----------- ------------ -------- ----------- --- ------------------
DB 40757346 aaa 1 8.1.7.4.0 NO server

Snap Id Snap Time Sessions
------- ------------------ --------
Begin Snap: 2845 31-10月-03 02:10:16 46
End Snap: 2848 31-10月-03 03:40:05 46
Elapsed: 89.82 (mins)


对于一个Statspack的report,采样时间是非常重要的维度,离开时间做参考,任何等待都不足以说明问题。

Cache Sizes
~~~~~~~~~~~
db_block_buffers: 51200 log_buffer: 2097152
db_block_size: 16384 shared_pool_size: 209715200
………..
Top 5 Wait Events
~~~~~~~~~~~~~~~~~ Wait % Total
Event Waits Time (cs) Wt Time
-------------------------------------------- ------------ ------------ -------
enqueue 53,793 16,192,686 67.86
rdbms ipc message 19,999 5,927,350 24.84
pmon timer 1,754 538,797 2.26
smon timer 17 522,281 2.19
SQL*Net message from client 94,525 520,104 2.18
-------------------------------------------------------------

在Statspack分析中,Top 5等待事件是我们最为关注的部分。
这个系统中,除了enqueue 等待事件以外,其他4个都属于空闲等待事件,无须关注。我们来关注一下enqueue等
待事件,在89.82 (mins)的采样间隔内,累计enqueue等待长达16,192,686cs,即45小时左右。这个等待已经太过
显著,实际上这个系统也正因此遭遇了巨大的困难,观察到队列等待以后,我们就应该关注队列等待在等待什么
资源。快速跳转的Statspack的其他部分,我们看到以下详细内容:

Enqueue activity for DB: DB Instance: aaa Snaps: 2716 -2718
-> ordered by waits desc, gets desc

Enqueue Gets Waits
---------- ------------ ----------
ST 1,554 1,554
-------------------------------------------------------------

我们看到主要队列等待在等待ST锁定,对于DMT,我们说这个等待跟FET$,UET$的争用紧密相关。我们在回过头来
研究捕获的SQL语句:

-> End Buffer Gets Threshold: 10000
-> Note that resources reported for PL/SQL includes the resources used by
all SQL statements called within the PL/SQL code. As individual SQL
statements are also reported, it is possible and valid for the summed
total % to exceed 100

Buffer Gets Executions Gets per Exec % Total Hash Value
--------------- ------------ -------------- ------- ------------
4,800,073 10,268 467.5 51.0 2913840444
select length from fet$ where file#=:1 and block#=:2 and ts#=:3

803,187 10,223 78.6 8.5 528349613
delete from uet$ where ts#=:1 and segfile#=:2 and segblock#=:3 a
nd ext#=:4

454,444 10,300 44.1 4.8 1839874543
select file#,block#,length from uet$ where ts#=:1 and segfile#=:
2 and segblock#=:3 and ext#=:4

23,110 10,230 2.3 0.2 3230982141
insert into fet$ (file#,block#,ts#,length) values (:1,:2,:3,:4)

21,201 347 61.1 0.2 1705880752
select file# from file$ where ts#=:1
….
9,505 12 792.1 0.1 1714733582
select f.file#, f.block#, f.ts#, f.length from fet$ f, ts$ t whe
re t.ts#=f.ts# and t.dflextpct!=0 and t.bitmapped=0

6,426 235 27.3 0.1 1877781575
delete from fet$ where file#=:1 and block#=:2 and ts#=:3

我们看到数据库频繁操作UET$,FET$系统表已经成为了系统的主要瓶颈。
至此,我们已经可以准确的为该系统定位问题,相应的解决方案也很容易确定,在8.1.7中,使用LMT代替DMT,
这是解决问题的根本办法,当然实施起来还要进行综合考虑,实际情况还要复杂得多。

HW enqueue指和段的高水位标记相关等待;手动分配适当区可以避免这一等待。

TX是最常见的enqueue等待。TX enqueue等待通常是以下三个问题之一产生的结果。
第一个问题是唯一索引中的重复索引,你需要执行提交(commit)/回滚(rollback)操作来释放enqueue。
第二个问题是对同一位图索引段的多次更新。因为单个位图段可能包含多个行地址(rowid),所以当多个用户试图更新同一段时,可能一个
用户会锁定其他用户请求的记录,这时等待出现。直到获得锁定的用户提交或回滚, enqueue释放。
第三个问题,也是最可能发生的问题是多个用户同时更新同一个块。如果没有足够的ITL槽,就会发生块级锁定。通过增大initrans和/或
maxtrans以允许使用多个ITL槽(对于频繁并发进行DML操作的数据表,在建表之初就应该考虑为相应参数设置合理的数值,避免系统运行
以后在线的更改,在8i之前,freelists等参数不能在线更改,设计时的考虑就尤为重要),或者增大表上的pctfree值,就可以很容易的避免
这种情况。
TM enqueue队列锁在进行DML操作前获得,以阻止对正在操作的数据表进行任何DDL操作(在DML操作一个数据表时,其结构不能被更改)。

14."log file sync" 等待事件

当一个用户提交(commits)或者回滚(rollback),session的redo信息需要写出到redo logfile中.
用户进程将通知LGWR执行写出操作,LGWR完成任务以后会通知用户进程.
这个等待事件就是指用户进程等待LGWR的写完成通知.

对于回滚操作,该事件记录从用户发出rollback命令到回滚完成的时间.

如果该等待过多,可能说明LGWR的写出效率低下,或者系统提交过于频繁.
针对该问题,可以关注:
log file parallel write等待事件
user commits,user rollback等统计信息可以用于观察提交或回滚次数

解决方案:
1.提高LGWR性能
尽量使用快速磁盘,不要把redo log file存放在raid 5的磁盘上
2.使用批量提交
3.适当使用NOLOGGING/UNRECOVERABLE等选项

可以通过如下公式计算平均redo写大小:

avg.redo write size = (Redo block written/redo writes)*512 bytes

如果系统产生redo很多,而每次写的较少,一般说明LGWR被过于频繁的激活了.
可能导致过多的redo相关latch的竞争,而且Oracle可能无法有效的使用piggyback的功能.

我们从一个statspack中提取一些数据来研究一下这个问题.

1.主要信息



DB Name DB Id Instance Inst Num Release OPS Host
------------ ----------- ------------ -------- ----------- --- ------------
DB 1222010599 oracle 1 8.1.7.4.5 NO sun
Snap Id Snap Time Sessions
------- ------------------ --------
Begin Snap: 3473 13-Oct-04 13:43:00 540
End Snap: 3475 13-Oct-04 14:07:28 540
Elapsed: 24.47 (mins)

Cache Sizes
~~~~~~~~~~~
db_block_buffers: 102400 log_buffer: 20971520
db_block_size: 8192 shared_pool_size: 600M

Load Profile
~~~~~~~~~~~~ Per Second Per Transaction
--------------- ---------------
Redo size: 28,458.11 2,852.03
......

2.等待事件

Event Waits Timeouts Time (cs) (ms) /txn
---------------------------- ------------ ---------- ----------- ------ ------
log file sync 14,466 2 4,150 3 1.0
db file sequential read 17,202 0 2,869 2 1.2
latch free 24,841 13,489 2,072 1 1.7
direct path write 121 0 1,455 120 0.0
db file parallel write 1,314 0 1,383 11 0.1
log file sequential read 1,540 0 63 0 0.1
....
log file switch completion 1 0 3 30 0.0
refresh controlfile command 23 0 1 0 0.0
LGWR wait for redo copy 46 0 0 0 0.0
....
log file single write 4 0 0 0 0.0

我们看到,这里log file sync和db file parallel write等待同时出现了.
显然log file sync在等待db file parallel write的完成.

这里磁盘IO肯定存在了瓶颈,实际用户的redo和数据文件同时存放在Raid的磁盘上,存在性能问题.
需要调整.

3.统计信息

Statistic Total per Second per Trans
--------------------------------- ---------------- ------------ ------------
....
redo blocks written 93,853 63.9 6.4
redo buffer allocation retries 1 0.0 0.0
redo entries 135,837 92.5 9.3
redo log space requests 1 0.0 0.0
redo log space wait time 3 0.0 0.0
redo ordering marks 0 0.0 0.0
redo size 41,776,508 28,458.1 2,852.0
redo synch time 4,174 2.8 0.3
redo synch writes 14,198 9.7 1.0
redo wastage 4,769,200 3,248.8 325.6
redo write time 3,698 2.5 0.3
redo writer latching time 0 0.0 0.0
redo writes 14,572 9.9 1.0
....
sorts (disk) 4 0.0 0.0
sorts (memory) 179,856 122.5 12.3
sorts (rows) 2,750,980 1,874.0 187.8
....
transaction rollbacks 36 0.0 0.0
transaction tables consistent rea 0 0.0 0.0
transaction tables consistent rea 0 0.0 0.0
user calls 1,390,718 947.4 94.9
user commits 14,136 9.6 1.0
user rollbacks 512 0.4 0.0
write clones created in backgroun 0 0.0 0.0
write clones created in foregroun 11 0.0 0.0
-------------------------------------------------------------


avg.redo write size = (Redo block written/redo writes)*512 bytes
= ( 93,853 / 14,572 )*512
= 3K

这个平均过小了,说明系统的提交过于频繁.
[color=teal]
Latch Sleep breakdown for DB: DPSHDB Instance: dpshdb Snaps: 3473 -3475
-> ordered by misses desc

Get Spin &
Latch Name Requests Misses Sleeps Sleeps 1->4
-------------------------- -------------- ----------- ----------- ------------
row cache objects 12,257,850 113,299 64 113235/64/0/
0/0
shared pool 3,690,715 60,279 15,857 52484/588/65
46/661/0
library cache 4,912,465 29,454 8,876 23823/2682/2
733/216/0
cache buffers chains 10,314,526 2,856 33 2823/33/0/0/
0
redo writing 76,550 937 1 936/1/0/0/0
session idle bit 2,871,949 225 1 224/1/0/0/0
messages 107,950 159 2 157/2/0/0/0
session allocation 184,386 44 6 38/6/0/0/0
checkpoint queue latch 96,583 1 1 0/1/0/0/0
-------------------------------------------------------------[/c[/color]

由于过渡频繁的提交,LGWR过度频繁的激活,我们看到这里出现了redo writing的latch竞争.

关于redo writing竞争你可以在steve的站点找到详细的介绍:


转引如下:
" target="_blank">http://www.ixora.com.au/notes/lgwr_latching.htm


转引如下:

When LGWR wakes up, it first takes the redo writing latch to update the SGA variable that shows whether it is active. This prevents other Oracle processes from posting LGWR needlessly. LGWR then takes the redo allocation latch to determine how much redo might be available to write (subject to the release of the redo copy latches). If none, it takes the redo writing latch again to record that it is no longer active, before starting another rdbms ipc message wait.
If there is redo to write, LGWR then inspects the latch recovery areas for the redo copy latches (without taking the latches) to determine whether there are any incomplete copies into the log buffer. For incomplete copies above the sync RBA, LGWR just defers the writing of that block and subsequent log buffer blocks. For incomplete copies below the sync RBA, LGWR sleeps on a LGWR wait for redo copy wait event, and is posted when the required copy latches have been released. The time taken by LGWR to take the redo writing and redo allocation latches and to wait for the redo copy latches is accumulated in the redo writer latching time statistic.

(Prior to release 8i, foreground processes held the redo copy latches more briefly because they did not retain them for the application of the change vectors. Therefore, LGWR would instead attempt to assure itself that there were no ongoing copies into the log buffer by taking all the redo copy latches.)

After each redo write has completed, LGWR takes the redo allocation latch again in order to update the SGA variable containing the base disk block for the log buffer. This effectively frees the log buffer blocks that have just been written, so that they may be reused.
[@more@]

来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/503782/viewspace-983111/,如需转载,请注明出处,否则将追究法律责任。

请登录后发表评论 登录
全部评论
  • 博文量
    87
  • 访问量
    530260