October 14, 2004
Statspack之十四-"log file sync" 等待事件
作者:eygle
出处:http://blog.eygle.com
当一个用户提交(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
这个平均过小了，说明系统的提交过于频繁.
|
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
-------------------------------------------------------------
|
由于过渡频繁的提交，LGWR过度频繁的激活，我们看到这里出现了redo writing的latch竞争.
关于redo writing竞争你可以在steve的站点找到详细的介绍:
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. (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. |
Posted by eygle at 10:25 PM | Comments (2)
Statspack之十三-Enqueue
作者:eygle
出处:http://blog.eygle.com
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操作一个数据表时，其结构不能被更改)。
Posted by eygle at 10:23 PM | Comments (1)
Statspack之十二-db file scattered read-DB文件分散读取
作者:eygle
出处:http://blog.eygle.com
这种情况通常显示与全表扫描相关的等待。
当数据库进行全表扫时，基于性能的考虑，数据会分散(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
在创建了合适的索引后，系统性能得到了大幅提高!
|
Posted by eygle at 10:21 PM | Comments (0)
丢失所有文件、拥有全备份,缺少后增加的文件
作者:eygle
出处:http://blog.eygle.com
演示几种情况，不做过多说明.
归档模式
拥有所有归档文件及日志文件，丢失所有数据文件及控制文件，后增加的文件无备份，丢失这个文件，拥有控制文件及所有其他文件的历史
备份，以下是一种恢复情况.
1.测试,移除当前所有文件
从备份中恢复数据文件及控制文件(丢失后增加的文件)
SQL> startup; ORACLE 例程已经启动。 Total System Global Area 47259136 bytes Fixed Size 454144 bytes Variable Size 29360128 bytes Database Buffers 16777216 bytes Redo Buffers 667648 bytes 数据库装载完毕。 数据库已经打开。 SQL> archive log start; 已处理的语句 SQL> archive log list; 数据库日志模式 存档模式 自动存档 启用 存档终点 e:\oracle\ora92\RDBMS 最早的概要日志序列 30 下一个存档日志序列 32 当前日志序列 32 SQL> select name from v$datafile; NAME -------------------------------------------------------------------------------- E:\ORACLE\ORADATA\EYGLE\SYSTEM01.DBF E:\ORACLE\ORADATA\EYGLE\UNDOTBS01.DBF E:\ORACLE\ORADATA\EYGLE\EYGLE01.DBF SQL> create tablespace test datafile 'e:\oracle\oradata\eygle\test01.dbf' 2 size 5m; 表空间已创建。 SQL> alter system switch logfile; 系统已更改。 SQL> create table t tablespace test as select * from dba_users; 表已创建。 SQL> alter system switch logfile; 系统已更改。 SQL> shutdown abort; ORACLE 例程已经关闭。 SQL> exit 从Oracle9i Enterprise Edition Release 9.2.0.5.0 - Production With the Partitioning, OLAP and Oracle Data Mining options JServer Release 9.2.0.5.0 - Production中断开 E:\Oracle\oradata\eygle>mv TEST01.DBF bak E:\Oracle\oradata\eygle>mkdir bak2 E:\Oracle\oradata\eygle>mv *.* bak2 E:\Oracle\oradata\eygle>ls bak bak2 E:\Oracle\oradata\eygle>mv bak\*.* . --从备份中恢复 E:\Oracle\oradata\eygle>ls CONTROL01.CTL CONTROL03.CTL REDO01.LOG REDO03.LOG TEMP01.DBF UNDOTBS01.DBF bak2 CONTROL02.CTL EYGLE01.DBF REDO02.LOG SYSTEM01.DBF TEST01.DBF bak sqlnet.log E:\Oracle\oradata\eygle>mv TEST01.DBF bak --移除后增加的这个文件 E:\Oracle\oradata\eygle>ls CONTROL01.CTL CONTROL03.CTL REDO01.LOG REDO03.LOG TEMP01.DBF bak sqlnet.log CONTROL02.CTL EYGLE01.DBF REDO02.LOG SYSTEM01.DBF UNDOTBS01.DBF bak2 |
2.开始恢复
|
E:\Oracle\oradata\eygle>sqlplus "sys/oracle as sysdba"
SQL*Plus: Release 9.2.0.5.0 - Production on 星期三 10月 13 23:50:06 2004
Copyright (c) 1982, 2002, Oracle Corporation. All rights reserved.
已连接到空闲例程。
SQL> startup mount;
ORACLE 例程已经启动。
Total System Global Area 47259136 bytes
Fixed Size 454144 bytes
Variable Size 29360128 bytes
Database Buffers 16777216 bytes
Redo Buffers 667648 bytes
数据库装载完毕。
SQL> recover database using backup controlfile until cancel;
ORA-00279: 更改 134694 (在 10/13/2004 22:14:13 生成) 对于线程 1 是必需的
ORA-00289: 建议: E:\ORACLE\ORA92\RDBMS\ARC00032.001
ORA-00280: 更改 134694 对于线程 1 是按序列 # 32 进行的
指定日志: { |
注意:由于使用的是备份的控制文件进行恢复，该文件中不包含后增加的文件，恢复过程中会缺省的赋予一个文件名，本案例时:UNNAMED00004
3.更改文件名称继续恢复
|
SQL> alter database create datafile 'E:\ORACLE\ORA92\DATABASE\UNNAMED00004'
as 'E:\ORACLE\ORADATA\EYGLE\TEST01.DBF';
数据库已更改。
SQL> recover database using backup controlfile until cancel;
ORA-00279: 更改 134923 (在 10/13/2004 22:40:10 生成) 对于线程 1 是必需的
ORA-00289: 建议: E:\ORACLE\ORA92\RDBMS\ARC00032.001
ORA-00280: 更改 134923 对于线程 1 是按序列 # 32 进行的
指定日志: { |
总结:
此案例丢失控制文件，从备份控制文件进行恢复，在进行恢复中，会向控制文件中以缺省规则增加文件，我们可以通过CREATE AS方式修改控制文件中记录.
继续应用所有归档和日志文件可以完成恢复.
Posted by eygle at 11:56 AM | Comments (3)
Oracle HowTo:如何查看各个表空间的自由空间
作者:eygle
出处:http://blog.eygle.com
DBA_FREE_SPACE视图记录了数据库中所有表空间的自由extents情况，所以可以从该视图获得各表空间自由空间情况。 SQL> desc dba_free_space Name Null? Type ----------------------- ------------- ----------------- TABLESPACE_NAME VARCHAR2(30) FILE_ID NUMBER BLOCK_ID NUMBER BYTES NUMBER BLOCKS NUMBER RELATIVE_FNO NUMBER |
可以使用如下SQL进行查询:
select tablespace_name,sum(bytes)/1024/1024 free_Mbytes from dba_free_space group by tablespace_name order by free_Mbytes / |
示例输出:
SQL> select tablespace_name,sum(bytes)/1024/1024 free_Mbytes 2 from dba_free_space 3 group by tablespace_name 4 order by free_Mbytes 5 / TABLESPACE_NAME FREE_MBYTES -------------------- ----------- USERS .75 UNDOTBS1 18.6875 SYSTEM 42.6875 |
Posted by eygle at 9:55 AM | Comments (0)