啥是AWR?
=====================================================================================================
AWR (Automatic Workload Repository)
一堆历史性能数据,放在SYSAUX表空间上, AWR和SYSAUX都是10g出现的,是Oracle调优的关键特性; 大约1999年左右开始开发,已经有15年历史
默认快照间隔1小时,10g保存7天、11g保存8天; 可以通过DBMS_WORKLOAD_REPOSITORY.MODIFY_SNAPSHOT_SETTINGS修改
DBA_HIST_WR_CONTROL
AWR程序核心是dbms_workload_repository包
@?/rdbms/admin/awrrpt 本实例
@?/rdbms/admin/awrrpti RAC中选择实例号
谁维护AWR?
主要是MMON(Manageability Monitor Process)和它的小工进程(m00x)
MMON的功能包括:
1.启动slave进程m00x去做AWR快照
2.当某个度量阀值被超过时发出alert告警
3.为最近改变过的SQL对象捕获指标信息
AWR小技巧
手动执行一个快照:
Exec dbms_workload_repository.create_snapshot; (这个要背出来哦,用的时候去翻手册,丢脸哦 J!)
创建一个AWR基线
Exec DBMS_WORKLOAD_REPOSITORY.CREATE_BASELINE(start_snap_id,end_snap_id ,baseline_name);
@?/rdbms/admin/awrddrpt AWR比对报告
@?/rdbms/admin/awrgrpt RAC 全局AWR
自动生成AWR HTML报告:
http://www.oracle-base.com/dba/10g/generate_multiple_awr_reports.sql
1、报告总结
WORKLOAD REPOSITORY report for DB Name DB Id Instance Inst Num Startup Time Release RAC ------------ ----------- ------------ -------- --------------- ----------- --- MAC 2629627371 askmaclean.com 1 22-Jan-13 16:49 11.2.0.3.0 YES Host Name Platform CPUs Cores Sockets Memory(GB) ---------------- -------------------------------- ---- ----- ------- ---------- MAC10 AIX-Based Systems (64-bit) 128 32 320.00 Snap Id Snap Time Sessions Curs/Sess --------- ------------------- -------- --------- Begin Snap: 5853 23-Jan-13 15:00:56 3,520 1.8 End Snap: 5854 23-Jan-13 15:30:41 3,765 1.9 Elapsed: 29.75 (mins) DB Time: 7,633.76 (mins)
Elapsed 为该AWR性能报告的时间跨度(自然时间的跨度,例如前一个快照snapshot是4点生成的,后一个快照snapshot是6点生成的,则若使用@?/rdbms/admin/awrrpt 脚本中指定这2个快照的话,那么其elapsed = (6-4)=2 个小时),一个AWR性能报告 至少需要2个AWR snapshot性能快照才能生成 ( 注意这2个快照时间 实例不能重启过,否则指定这2个快照生成AWR性能报告 会报错),AWR性能报告中的 指标往往是 后一个快照和前一个快照的 指标的delta,这是因为 累计值并不能反映某段时间内的系统workload。
DB TIME= 所有前台session花费在database调用上的总和时间:
- 注意是前台进程foreground sessions
- 包括CPU时间、IO Time、和其他一系列非空闲等待时间,别忘了cpu on queue time
DB TIME 不等于 响应时间,DB TIME高了未必响应慢,DB TIME低了未必响应快
DB Time描绘了数据库总体负载,但要和elapsed time逝去时间结合其他来。
Average Active Session AAS= DB time/Elapsed Time
DB Time =60 min , Elapsed Time =60 min AAS=60/60=1 负载一般
DB Time= 1min , Elapsed Time= 60 min AAS= 1/60 负载很轻
DB Time= 60000 min,Elapsed Time= 60 min AAS=1000 系统hang了吧?
DB TIME= DB CPU + Non-Idle Wait + Wait on CPU queue
如果仅有2个逻辑CPU,而2个session在60分钟都没等待事件,一直跑在CPU上,那么:
DB CPU= 2 * 60 mins , DB Time = 2* 60 + 0 + 0 =120
AAS = 120/60=2 正好等于OS load 2。
如果有3个session都100%仅消耗CPU,那么总有一个要wait on queue
DB CPU = 2* 60 mins ,wait on CPU queue= 60 mins
AAS= (120+ 60)/60=3 主机load 亦为3,此时vmstat 看waiting for run time
真实世界中? DB Cpu = xx mins , Non-Idle Wait= enq:TX + cursor pin S on X + latch : xxx + db file sequential read + ……….. 阿猫阿狗
1-1 内存参数大小
Cache Sizes Begin End ~~~~~~~~~~~ ---------- ---------- Buffer Cache: 49,152M 49,152M Std Block Size: 8K Shared Pool Size: 13,312M 13,312M Log Buffer: 334,848K
内存管理方式:MSMM、ASMM(sga_target)、AMM(memory_target)
小内存有小内存的问题, 大内存有大内存的麻烦! ORA-04031???!!
Buffer cache和shared pool size的 begin/end值在ASMM、AMM和11gR2 MSMM下可是会动的哦!
这里说 shared pool一直收缩,则在shrink过程中一些row cache 对象被lock住可能导致前台row cache lock等解析等待,最好别让shared pool shrink。如果这里shared pool一直在grow,那说明shared pool原有大小不足以满足需求(可能是大量硬解析),结合下文的解析信息和SGA breakdown来一起诊断问题。
1-2 Load Profile
Load Profile Per Second Per Transaction Per Exec Per Call ~~~~~~~~~~~~ --------------- --------------- ---------- ---------- DB Time(s): 256.6 0.2 0.07 0.03 DB CPU(s): 3.7 0.0 0.00 0.00 Redo size: 1,020,943.0 826.5 Logical reads: 196,888.0 159.4 Block changes: 6,339.4 5.1 Physical reads: 5,076.7 4.1 Physical writes: 379.2 0.3 User calls: 10,157.4 8.2 Parses: 204.0 0.2 Hard parses: 0.9 0.0 W/A MB processed: 5.0 0.0 Logons: 1.7 0.0 Executes: 3,936.6 3.2 Rollbacks: 1,126.3 0.9 Transactions: 1,235.3 % Blocks changed per Read: 53.49 Recursive Call %: 98.04 Rollback per transaction %: 36.57 Rows per Sort: 73.70
指标 | 指标含义 |
redo size | 单位 bytes,redo size可以用来估量update/insert/delete的频率,大的redo size往往对lgwr写日志,和arch归档造成I/O压力, Per Transaction可以用来分辨是 大量小事务, 还是少量大事务。如上例每秒redo 约1MB ,每个事务800 字节,符合OLTP特征 |
Logical Read | 单位 次数*块数, 相当于 “人*次”, 如上例 196,888 * db_block_size=1538MB/s , 逻辑读耗CPU,主频和CPU核数都很重要,逻辑读高则DB CPU往往高,也往往可以看到latch: cache buffer chains等待。 大量OLTP系统(例如siebel)可以高达几十乃至上百Gbytes。 |
Block changes | 单位 次数*块数 , 描绘数据变化频率 |
Physical Read | 单位次数*块数, 如上例 5076 * 8k = 39MB/s, 物理读消耗IO读,体现在IOPS和吞吐量等不同纬度上;但减少物理读可能意味着消耗更多CPU。好的存储 每秒物理读能力达到几GB,例如Exadata。 这个physical read包含了physical reads cache和physical reads direct |
Physical writes | 单位 次数*块数,主要是DBWR写datafile,也有direct path write。 dbwr长期写出慢会导致定期log file switch(checkpoint no complete) 检查点无法完成的前台等待。 这个physical write 包含了physical writes direct +physical writes from cache |
User Calls | 单位次数,用户调用数,more details from internal |
Parses | 解析次数,包括软解析+硬解析,软解析优化得不好,则夸张地说几乎等于每秒SQL执行次数。 即执行解析比1:1,而我们希望的是 解析一次 到处运行哦! |
Hard Parses | 万恶之源. Cursor pin s on X, library cache: mutex X , latch: row cache objects /shared pool……………..。 硬解析最好少于每秒20次 |
W/A MB processed | 单位MB W/A workarea workarea中处理的数据数量 结合 In-memory Sort%, sorts (disk) PGA Aggr一起看 |
Logons | 登陆次数, logon storm 登陆风暴,结合AUDIT审计数据一起看。短连接的附带效应是游标缓存无用 |
Executes | 执行次数,反应执行频率 |
Rollback | 回滚次数, 反应回滚频率, 但是这个指标不太精确,参考而已,别太当真 |
Transactions | 每秒事务数,是数据库层的TPS,可以看做压力测试或比对性能时的一个指标,孤立看无意义 |
% Blocks changed per Read | 每次逻辑读导致数据块变化的比率;如果’redo size’, ‘block changes’ ‘pct of blocks changed per read’三个指标都很高,则说明系统正执行大量insert/update/delete; pct of blocks changed per read = (block changes ) /( logical reads) |
Recursive Call % | 递归调用的比率;Recursive Call % = (recursive calls)/(user calls) |
Rollback per transaction % | 事务回滚比率。 Rollback per transaction %= (rollback)/(transactions) |
Rows per Sort | 平均每次排序涉及到的行数 ; Rows per Sort= ( sorts(rows) ) / ( sorts(disk) + sorts(memory)) |
注意这些Load Profile 负载指标 在本环节提供了 2个维度 per second 和 per transaction。
per Second: 主要是把 快照内的delta值除以 快站时间的秒数 , 例如 在 A快照中V$SYSSTAT视图反应 table scans (long tables) 这个指标是 100 ,在B快照中V$SYSSTAT视图反应 table scans (long tables) 这个指标是 3700, 而A快照和B快照 之间 间隔了一个小时 3600秒, 则 对于 table scans (long tables) per second 就是 ( 3700- 100) /3600=1。
pert Second是我们审视数据的主要维度 ,任何性能数据脱离了 时间模型则毫无意义。
在statspack/AWR出现之前 的调优 洪荒时代, 有很多DBA 依赖 V$SYSSTAT等视图中的累计 统计信息来调优,以当前的调优眼光来看,那无异于刀耕火种。
per transaction : 基于事务的维度, 与per second相比 是把除数从时间的秒数改为了该段时间内的事务数。 这个维度的很大用户是用来 识别应用特性的变化 ,若2个AWR性能报告中该维度指标 出现了大幅变化,例如 redo size从本来per transaction 1k变化为 10k per transaction,则说明SQL业务逻辑肯定发生了某些变化。
注意AWR中的这些指标 并不仅仅用来孤立地了解 Oracle数据库负载情况, 实施调优工作。 对于 故障诊断 例如HANG、Crash等, 完全可以通过对比问题时段的性能报告和常规时间来对比,通过各项指标的对比往往可以找出 病灶所在。
SELECT VALUE FROM DBA_HIST_SYSSTAT WHERE SNAP_ID = :B4 AND DBID = :B3 AND INSTANCE_NUMBER = :B2 AND STAT_NAME in ( "db block changes","user calls","user rollbacks","user commits",redo size","physical reads direct","physical writes","parse count (hard)","parse count (total)","session logical reads","recursive calls","redo log space requests","redo entries","sorts (memory)","sorts (disk)","sorts (rows)","logons cumulative","parse time cpu","parse time elapsed","execute count","logons current","opened cursors current","DBWR fusion writes","gcs messages sent","ges messages sent","global enqueue gets sync","global enqueue get time","gc cr blocks received","gc cr block receive time","gc current blocks received","gc current block receive time","gc cr blocks served","gc cr block build time","gc cr block flush time","gc cr block send time","gc current blocks served","gc current block pin time","gc current block flush time","gc current block send time","physical reads","physical reads direct (lob)", SELECT TOTAL_WAITS FROM DBA_HIST_SYSTEM_EVENT WHERE SNAP_ID = :B4 AND DBID = :B3 AND INSTANCE_NUMBER = :B2 AND EVENT_NAME in ("gc buffer busy","buffer busy waits" SELECT VALUE FROM DBA_HIST_SYS_TIME_MODEL WHERE DBID = :B4 AND SNAP_ID = :B3 AND INSTANCE_NUMBER = :B2 AND STAT_NAME in ("DB CPU","sql execute elapsed time","DB time" SELECT VALUE FROM DBA_HIST_PARAMETER WHERE SNAP_ID = :B4 AND DBID = :B3 AND INSTANCE_NUMBER = :B2 AND PARAMETER_NAME in ("__db_cache_size","__shared_pool_size","sga_target","pga_aggregate_target","undo_management","db_block_size","log_buffer","timed_statistics","statistics_level" SELECT BYTES FROM DBA_HIST_SGASTAT WHERE SNAP_ID = :B4 AND DBID = :B3 AND INSTANCE_NUMBER = :B2 AND POOL IN (‘shared pool‘, ‘all pools‘) AND NAME in ("free memory", SELECT BYTES FROM DBA_HIST_SGASTAT WHERE SNAP_ID = :B4 AND DBID = :B3 AND INSTANCE_NUMBER = :B2 AND NAME = :B1 AND POOL IS NULL SELECT (E.BYTES_PROCESSED - B.BYTES_PROCESSED) FROM DBA_HIST_PGA_TARGET_ADVICE B, DBA_HIST_PGA_TARGET_ADVICE E WHERE B.DBID = :B4 AND B.SNAP_ID = :B3 AND B.INSTANCE_NUM BER = :B2 AND B.ADVICE_STATUS = ‘ON‘ AND E.DBID = B.DBID AND E.SNAP_ID = :B1 AND E.INSTANCE_NUMBER = B.INSTANCE_NUMBER AND E.PGA_TARGET_FACTOR = 1 AND B.PGA_TARGET_FACT OR = 1 AND E.ADVICE_STATUS = ‘ON‘ SELECT SUM(E.TOTAL_WAITS - NVL(B.TOTAL_WAITS, 0)) FROM DBA_HIST_SYSTEM_EVENT B, DBA_HIST_SYSTEM_EVENT E WHERE B.SNAP_ID(+) = :B4 AND E.SNAP_ID = :B3 AND B.DBID(+) = :B2 AND E.DBID = :B2 AND B.INSTANCE_NUMBER(+) = :B1 AND E.INSTANCE_NUMBER = :B1 AND B.EVENT_ID(+) = E.EVENT_ID AND (E.EVENT_NAME = ‘latch free‘ OR E.EVENT_NAME LIKE ‘latch :%‘) SELECT DECODE(B.TOTAL_SQL, 0, 0, 100*(1-B.SINGLE_USE_SQL/B.TOTAL_SQL)), DECODE(E.TOTAL_SQL, 0, 0, 100*(1-E.SINGLE_USE_SQL/E.TOTAL_SQL)), DECODE(B.TOTAL_SQL_MEM, 0, 0, 1 00*(1-B.SINGLE_USE_SQL_MEM/B.TOTAL_SQL_MEM)), DECODE(E.TOTAL_SQL_MEM, 0, 0, 100*(1-E.SINGLE_USE_SQL_MEM/E.TOTAL_SQL_MEM)) FROM DBA_HIST_SQL_SUMMARY B, DBA_HIST_SQL_SUMM ARY E WHERE B.SNAP_ID = :B4 AND E.SNAP_ID = :B3 AND B.INSTANCE_NUMBER = :B2 AND E.INSTANCE_NUMBER = :B2 AND B.DBID = :B1 AND E.DBID = :B1 SELECT EVENT, WAITS, TIME, DECODE(WAITS, NULL, TO_NUMBER(NULL), 0, TO_NUMBER(NULL), TIME/WAITS*1000) AVGWT, PCTWTT, WAIT_CLASS FROM (SELECT EVENT, WAITS, TIME, PCTWTT, WAIT_CLASS FROM (SELECT E.EVENT_NAME EVENT, E.TOTAL_WAITS - NVL(B.TOTAL_WAITS,0) WAITS, (E.TIME_WAITED_MICRO - NVL(B.TIME_WAITED_MICRO,0)) / 1000000 TIME, 100 * (E.TIME _WAITED_MICRO - NVL(B.TIME_WAITED_MICRO,0)) / :B1 PCTWTT, E.WAIT_CLASS WAIT_CLASS FROM DBA_HIST_SYSTEM_EVENT B, DBA_HIST_SYSTEM_EVENT E WHERE B.SNAP_ID(+) = :B5 AND E.S NAP_ID = :B4 AND B.DBID(+) = :B3 AND E.DBID = :B3 AND B.INSTANCE_NUMBER(+) = :B2 AND E.INSTANCE_NUMBER = :B2 AND B.EVENT_ID(+) = E.EVENT_ID AND E.TOTAL_WAITS > NVL(B.TO TAL_WAITS,0) AND E.WAIT_CLASS != ‘Idle‘ UNION ALL SELECT ‘CPU time‘ EVENT, TO_NUMBER(NULL) WAITS, :B6 /1000000 TIME, 100 * :B6 / :B1 PCTWTT, NULL WAIT_CLASS FROM DUAL W HERE :B6 > 0) ORDER BY TIME DESC, WAITS DESC) WHERE ROWNUM <= :B7 SELECT SUM(E.TIME_WAITED_MICRO - NVL(B.TIME_WAITED_MICRO,0)) FROM DBA_HIST_SYSTEM_EVENT B, DBA_HIST_SYSTEM_EVENT E WHERE B.SNAP_ID(+) = :B4 AND E.SNAP_ID = :B3 AND B.DB ID(+) = :B2 AND E.DBID = :B2 AND B.INSTANCE_NUMBER(+) = :B1 AND E.INSTANCE_NUMBER = :B1 AND B.EVENT_ID(+) = E.EVENT_ID AND E.WAIT_CLASS = ‘User I/O‘ SELECT (E.ESTD_LC_TIME_SAVED - B.ESTD_LC_TIME_SAVED) FROM DBA_HIST_SHARED_POOL_ADVICE B, DBA_HIST_SHARED_POOL_ADVICE E WHERE B.DBID = :B3 AND B.INSTANCE_NUMBER = :B2 AN D B.SNAP_ID = :B4 AND E.DBID = :B3 AND E.INSTANCE_NUMBER = :B2 AND E.SNAP_ID = :B1 AND E.SHARED_POOL_SIZE_FACTOR = 1 AND B.SHARED_POOL_SIZE_FACTOR = 1
1-3 Instance Efficiency Percentages (Target 100%)
Instance Efficiency Percentages (Target 100%) ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Buffer Nowait %: 99.97 Redo NoWait %: 100.00 Buffer Hit %: 97.43 In-memory Sort %: 100.00 Library Hit %: 99.88 Soft Parse %: 99.58 Execute to Parse %: 94.82 Latch Hit %: 99.95 Parse CPU to Parse Elapsd %: 1.75 % Non-Parse CPU: 99.85
上述所有指标 的目标均为100%,即越大越好,在少数bug情况下可能超过100%或者为负值。
- 80%以上 %Non-Parse CPU
- 90%以上 Buffer Hit%, In-memory Sort%, Soft Parse%
- 95%以上 Library Hit%, Redo Nowait%, Buffer Nowait%
- 98%以上 Latch Hit%
1、 Buffer Nowait % session申请一个buffer(兼容模式)不等待的次数比例。 需要访问buffer时立即可以访问的比率, 不兼容的情况 在9i中是 buffer busy waits,从10g以后 buffer busy waits 分离为 buffer busy wait 和 read by other session2个等待事件 :
9i 中 waitstat的总次数基本等于buffer busy waits等待事件的次数 SQL> select sum(TOTAL_WAITS) from v$system_event where event=‘buffer busy waits‘; SUM(TOTAL_WAITS) —————- 33070394 SQL> select sum(count) from v$waitstat; SUM(COUNT) ———- 33069335 10g waitstat的总次数基本等于 buffer busy waits 和 read by other session 等待的次数总和 SQL> select sum(TOTAL_WAITS) from v$system_event where event=‘buffer busy waits‘ or event=‘read by other session‘; SUM(TOTAL_WAITS) —————- 60675815 SQL> select sum(count) from v$waitstat; SUM(COUNT) ———- 60423739
Buffer Nowait %的计算公式是 sum(v$waitstat.wait_count) / (v$sysstat statistic session logical reads),例如在AWR中:
Class | Waits | Total Wait Time (s) | Avg Time (ms) |
---|---|---|---|
data block | 24,543 | 2,267 | 92 |
undo header | 743 | 2 | 3 |
undo block | 1,116 | 0 | 0 |
1st level bmb | 35 | 0 | 0 |
session logical reads | 40,769,800 | 22,544.84 | 204.71 |
Buffer Nowait %: | 99.94 |
Buffer Nowait= ( 40,769,800 – (24543+743+1116+35))/ ( 40,769,800) = 0.99935= 99.94%
SELECT SUM(WAIT_COUNT) FROM DBA_HIST_WAITSTAT WHERE SNAP_ID = :B3 AND DBID = :B2 AND INSTANCE_NUMBER = :B1
2、buffer HIT%: 经典的经典,高速缓存命中率,反应物理读和缓存命中间的纠结,但这个指标即便99% 也不能说明物理读等待少了
不合理的db_cache_size,或者是SGA自动管理ASMM /Memory 自动管理AMM下都可能因为db_cache_size过小引起大量的db file sequential /scattered read等待事件; maclean曾经遇到过因为大量硬解析导致ASMM 下shared pool共享池大幅度膨胀,而db cache相应缩小shrink的例子,最终db cache收缩到只有几百兆,本来没有的物理读等待事件都大幅涌现出来 。
此外与 buffer HIT%相关的指标值得关注的还有 table scans(long tables) 大表扫描这个统计项目、此外相关的栏目还有Buffer Pool Statistics 、Buffer Pool Advisory等(如果不知道在哪里,直接找一个AWR 去搜索这些关键词即可)。
buffer HIT%在 不同版本有多个计算公式:
在9i中
Buffer Hit Ratio = 1 – ((physical reads – physical reads direct – physical reads direct (lob)) / (db block gets + consistent gets – physical reads direct – physical reads direct (lob))
在10g以后:
Buffer Hit Ratio= 1 – ((‘physical reads cache’) / (‘consistent gets from cache’ + ‘db block gets from cache’)
注意:但是实际AWR中 似乎还是按照9i中的算法,虽然算法的区别对最后算得的比率影响不大。
对于buffer hit % 看它的命中率有多高没有意义,主要是关注 未命中的次数有多少。通过上述公式很容易反推出未命中的物理读的次数。
db block gets 、consistent gets 以及 session logical reads的关系如下:
db block gets=db block gets direct+ db block gets from cache
consistent gets = consistent gets from cache+ consistent gets direct
consistent gets from cache= consistent gets – examination + else
consistent gets – examination==>指的是不需要pin buffer直接可以执行consistent get的次数,常用于索引,只需要一次latch get
session logical reads = db block gets +consistent gets
其中physical reads 、physical reads cache、physical reads direct、physical reads direct (lob)几者的关系为:
physical reads = physical reads cache + physical reads direct
这个公式其实说明了 物理读有2种 :
- 物理读进入buffer cache中 ,是常见的模式 physical reads cache
- 物理读直接进入PGA 直接路径读, 即physical reads direct
physical reads | 8 | Total number of data blocks read from disk. This value can be greater than the value of “physical reads direct” plus “physical reads cache” as reads into process private buffers also included in this statistic. |
physical reads cache | 8 | Total number of data blocks read from disk into the buffer cache. This is a subset of “physical reads” statistic. |
physical reads direct | 8 | Number of reads directly from disk, bypassing the buffer cache. For example, in high bandwidth, data-intensive operations such as parallel query, reads of disk blocks bypass the buffer cache to maximize transfer rates and to prevent the premature aging of shared data blocks resident in the buffer cache. |
physical reads direct = physical reads direct (lob) + physical reads direct temporary tablespace + physical reads direct(普通)
这个公式也说明了 直接路径读 分成三个部分:
- physical reads direct (lob) 直接路径读LOB对象
- physical reads direct temporary tablespace 直接路径读临时表空间
- physical read direct(普通) 普通的直接路径读, 一般是11g开始的自动的大表direct path read和并行引起的direct path read
physical writes direct= physical writes direct (lob)+ physical writes direct temporary tablespace
DBWR checkpoint buffers written = DBWR thread checkpoint buffers written+ DBWR tablespace checkpoint buffers written+ DBWR PQ tablespace checkpoint buffers written+….
3、Redo nowait%: session在生成redo entry时不用等待的比例,redo相关的资源争用例如redo space request争用可能造成生成redo时需求等待。此项数据来源于v$sysstat中的(redo log space requests/redo entries)。 一般来说10g以后不太用关注log_buffer参数的大小,需要关注是否有十分频繁的 log switch ; 过小的redo logfile size 如果配合较大的SGA和频繁的commit提交都可能造成该问题。 考虑增到redo logfile 的尺寸 : 1~4G 每个,7~10组都是合适的。同时考虑优化redo logfile和datafile 的I/O。
4、In-memory Sort%:这个指标因为它不计算workarea中所有的操作类型,所以现在越来越鸡肋了。 纯粹在内存中完成的排序比例。数据来源于v$sysstat statistics sorts (disk) 和 sorts (memory), In-memory Sort% = sort(memory) / ( sort(disk)+ sort(memory) )
5、
Library Hit%: library cache命中率,申请一个library cache object例如一个SQL cursor时,其已经在library cache中的比例。 数据来源 V$librarycache的pins和pinhits。 合理值:>95% ,该比例来源于1- ( Σ(pin Requests * Pct Miss) / Sum(Pin Requests) )
此外保证SQL语句绑定变量和游标可以共享也是很重要的因素。
Library Cache Activity DB/Inst: G10R25/G10R25 Snaps: 2964-2965 -> "Pct Misses" should be very low http://www.askmaclean.com Get Pct Pin Pct Invali- Namespace Requests Miss Requests Miss Reloads dations --------------- ------------ ------ -------------- ------ ---------- -------- BODY 5 0.0 6 16.7 1 0 CLUSTER 10 0.0 26 0.0 0 0 SQL AREA 601,357 99.8 902,828 99.7 47 2 TABLE/PROCEDURE 83 9.6 601,443 0.0 48 0
GETS |
NUMBER |
Number of times a lock was requested for objects of this namespace |
GETHITS |
NUMBER |
Number of times an object’s handle was found in memory |
GETHITRATIO |
NUMBER |
Ratio of GETHITS to GETS |
PINS |
NUMBER |
Number of times a PIN was requested for objects of this namespace |
PINHITS |
NUMBER |
Number of times all of the metadata pieces of the library object were found in memory |
PINHITRATIO |
NUMBER |
Ratio of PINHITS to PINS |
RELOADS |
NUMBER |
Any PIN of an object that is not the first PIN performed since the object handle was created, and which requires loading the object from disk |
INVALIDATIONS |
NUMBER |
Total number of times objects in this namespace were marked invalid because a dependent object was modified |
SELECT SUM(PINS), SUM(PINHITS) FROM DBA_HIST_LIBRARYCACHE WHERE SNAP_ID = :B3 AND DBID = :B2 AND INSTANCE_NUMBER = :B1
6、
Soft Parse: 软解析比例,无需多说的经典指标,数据来源v$sysstat statistics的parse count(total)和parse count(hard)。 合理值>95%
Soft Parse %是AWR中另一个重要的解析指标,该指标反应了快照时间内 软解析次数 和 总解析次数 (soft+hard 软解析次数+硬解析次数)的比值,若该指标很低,那么说明了可能存在剧烈的hard parse硬解析,大量的硬解析会消耗更多的CPU时间片并产生解析争用(此时可以考虑使用cursor_sharing=FORCE); 理论上我们总是希望 Soft Parse % 接近于100%, 但并不是说100%的软解析就是最理想的解析状态,通过设置session_cached_cursors参数和反复重用游标我们可以让解析来的更轻量级,即通俗所说的利用会话缓存游标实现的软软解析(soft soft parse)。
7、
Execute to Parse% 指标反映了执行解析比 其公式为 1-(parse/execute) , 目标为100% 及接近于只 执行而不解析。 数据来源v$sysstat statistics parse count (total) 和execute count
在oracle中解析往往是执行的先提工作,但是通过游标共享 可以解析一次 执行多次, 执行解析可能分成多种场景:
- hard coding => 硬编码代码 硬解析一次 ,执行一次, 则理论上其执行解析比 为 1:1 ,则理论上Execute to Parse =0 极差,且soft parse比例也为0%
- 绑定变量但是仍软解析=》 软解析一次,执行一次 , 这种情况虽然比前一种好 但是执行解析比(这里的parse,包含了软解析和硬解析)仍是1:1, 理论上Execute to Parse =0 极差, 但是soft parse比例可能很高
- 使用 静态SQL、动态绑定、session_cached_cursor、open cursors等技术实现的 解析一次,执行多次, 执行解析比为N:1, 则 Execute to Parse= 1- (1/N) 执行次数越多 Execute to Parse越接近100% ,这种是我们在OLTP环境中喜闻乐见的!
通俗地说 soft parse% 反映了软解析率, 而软解析在oracle中仍是较昂贵的操作, 我们希望的是解析1次执行N次,如果每次执行均需要软解析,那么虽然soft parse%=100% 但是parse time仍可能是消耗DB TIME的大头。
Execute to Parse反映了 执行解析比,Execute to Parse和soft parse% 都很低 那么说明确实没有绑定变量 , 而如果 soft parse% 接近99% 而Execute to Parse 不足90% 则说明没有执行解析比低, 需要通过 静态SQL、动态绑定、session_cached_cursor、open cursors等技术减少软解析。
8、
Latch Hit%: willing-to-wait latch闩申请不要等待的比例。 数据来源V$latch gets和misses
Latch Name ---------------------------------------- Get Requests Misses Sleeps Spin Gets Sleep1 Sleep2 Sleep3 -------------- ----------- ----------- ---------- -------- -------- -------- shared pool 9,988,637 364 23 341 0 0 0 library cache 6,753,468 152 6 146 0 0 0 Memory Management Latch 369 1 1 0 0 0 0 qmn task queue latch 24 1 1 0 0 0 0
Latch Hit%:= (1 – (Sum(misses) / Sum(gets)))
关于Latch的更多信息内容可以参考 AWR后面的专栏Latch Statistics, 注意对于一个并发设计良好的OLTP应用来说,Latch、Enqueue等并发控制不应当成为系统的主要瓶颈, 同时对于这些并发争用而言 堆积硬件CPU和内存 很难有效改善性能。
SELECT SUM(GETS), SUM(MISSES) FROM DBA_HIST_LATCH WHERE SNAP_ID = :B3 AND DBID = :B2 AND INSTANCE_NUMBER = :B1
9、
Parse CPU To Parse Elapsd:该指标反映了 快照内解析CPU时间和总的解析时间的比值(Parse CPU Time/ Parse Elapsed Time); 若该指标水平很低,那么说明在整个解析过程中 实际在CPU上运算的时间是很短的,而主要的解析时间都耗费在各种其他非空闲的等待事件上了(如latch:shared pool,row cache lock之类等) 数据来源 V$sysstat 的 parse time cpu和parse time elapsed
10、
%Non-Parse CPU 非解析cpu比例,公式为 (DB CPU – Parse CPU)/DB CPU, 若大多数CPU都用在解析上了,则可能好钢没用在刃上了。 数据来源 v$sysstat 的 parse time cpu和 cpu used by this session
1-4 Shared Pool Statistics
Shared Pool Statistics Begin End ------ ------ Memory Usage %: 84.64 79.67 % SQL with executions>1: 93.77 24.69 % Memory for SQL w/exec>1: 85.36 34.8
该环节提供一个大致的SQL重用及shared pool内存使用的评估。 应用是否共享SQL? 有多少内存是给只运行一次的SQL占掉的,对比共享SQL呢?
如果该环节中% SQL with executions>1的 比例 小于%90 , 考虑用下面链接的SQL去抓 硬编码的非绑定变量SQL语句。
利用FORCE_MATCHING_SIGNATURE捕获非绑定变量SQL
Memory Usage %: (shared pool 的实时大小- shared pool free memory)/ shared pool 的实时大小, 代表shared pool的空间使用率,虽然有使用率但没有标明碎片程度
% SQL with executions>1 复用的SQL占总的SQL语句的比率,数据来源 DBA_HIST_SQL_SUMMARY 的 SINGLE_USE_SQL和TOTAL_SQL:1 – SINGLE_USE_SQL / TOTAL_SQL
% Memory for SQL w/exec>1 执行2次以上的SQL所占内存占总的SQL内存的比率,数据来源DBA_HIST_SQL_SUMMARY 的SINGLE_USE_SQL_MEM和TOTAL_SQL_MEM:1 – SINGLE_USE_SQL_MEM / TOTAL_SQL_MEM
==》上面2个指标也可以用来大致了解shared pool中的内存碎片程序,因为SINGLE_USE_SQL 单次执行的SQL多的话,那么显然可能有较多的共享池内存碎片
SQL复用率低的原因一般来说就是硬绑定变量(hard Coding)未合理使用绑定变量(bind variable),对于这种现象短期无法修改代表使用绑定变量的可以ALTER SYSTEM SET CURSOR_SHARING=FORCE; 来绕过问题,对于长期来看还是要修改代码绑定变量。 Oracle 从11g开始宣称今后将废弃CURSOR_SHARING的SIMILAR选项,同时SIMILAR选项本身也造成了很多问题,所以一律不推荐用CURSOR_SHARING=SIMILAR。
如果memory usage%比率一直很高,则可以关注下后面sga breakdown中的shared pool free memory大小,一般推荐至少让free memroy有个300~500MB 以避免隐患。
1-5 Top 5 Timed Events
Top 5 Timed Events Avg %Total ~~~~~~~~~~~~~~~~~~ wait Call Event Waits Time (s) (ms) Time Wait Class ------------------------------ ------------ ----------- ------ ------ ---------- gc buffer busy 79,083 73,024 923 65.4 Cluster enq: TX - row lock contention 35,068 17,123 488 15.3 Applicatio CPU time 12,205 10.9 gc current request 2,714 3,315 1221 3.0 Cluster gc cr multi block request 83,666 1,008 12 0.9 Cluster
基于Wait Interface的调优是目前的主流!每个指标都重要!
基于命中比例的调优,好比是统计局的报告, 张财主家财产100万,李木匠家财产1万, 平均财产50.5万。
基于等待事件的调优,好比马路上100辆汽车的行驶记录表,上车用了几分钟, 红灯等了几分钟,拥堵塞了几分钟。。。
丰富的等待事件以足够的细节来描绘系统运行的性能瓶颈,这是Mysql梦寐以求的东西……
Waits : 该等待事件发生的次数, 对于DB CPU此项不可用
Times : 该等待事件消耗的总计时间,单位为秒, 对于DB CPU 而言是前台进程所消耗CPU时间片的总和,但不包括Wait on CPU QUEUE
Avg Wait(ms) : 该等待事件平均等待的时间, 实际就是 Times/Waits,单位ms, 对于DB CPU此项不可用
% Total Call Time, 该等待事件占总的call time的比率
total call time = total CPU time + total wait time for non-idle events
% Total Call Time = time for each timed event / total call time
Wait Class: 等待类型:
Concurrency,System I/O,User I/O,Administrative,Other,Configuration,Scheduler,Cluster,Application,Idle,Network,Commit
CPU 上在干什么?
逻辑读? 解析?Latch spin? PL/SQL、函数运算?
DB CPU/CPU time是Top 1 是好事情吗? 未必!
注意DB CPU不包含 wait on cpu queue!
SELECT e.event_name event, e.total_waits - NVL (b.total_waits, 0) waits, DECODE ( e.total_waits - NVL (b.total_waits, 0), 0, TO_NUMBER (NULL), DECODE ( e.total_timeouts - NVL (b.total_timeouts, 0), 0, TO_NUMBER (NULL), 100 * (e.total_timeouts - NVL (b.total_timeouts, 0)) / (e.total_waits - NVL (b.total_waits, 0)))) pctto, (e.time_waited_micro - NVL (b.time_waited_micro, 0)) / 1000000 time, DECODE ( (e.total_waits - NVL (b.total_waits, 0)), 0, TO_NUMBER (NULL), ( (e.time_waited_micro - NVL (b.time_waited_micro, 0)) / 1000) / (e.total_waits - NVL (b.total_waits, 0))) avgwt, DECODE (e.wait_class, ‘Idle‘, 99, 0) idle FROM dba_hist_system_event b, dba_hist_system_event e WHERE b.snap_id(+) = &bid AND e.snap_id = &eid --AND b.dbid(+) = :dbid --AND e.dbid = :dbid AND b.instance_number(+) = 1 AND e.instance_number = 1 AND b.event_id(+) = e.event_id AND e.total_waits > NVL (b.total_waits, 0) AND e.event_name NOT IN (‘smon timer‘, ‘pmon timer‘, ‘dispatcher timer‘, ‘dispatcher listen timer‘, ‘rdbms ipc message‘) ORDER BY idle, time DESC, waits DESC, event
几种常见的等待事件
=========================>
db file sequential read ,该等待事件Avg wait time平均单次等待时间应当小于20ms
”db file sequential read”单块读等待是一种最为常见的物理IO等待事件,这里的sequential指的是将数据块读入到相连的内存空间中(contiguous memory space),而不是指所读取的数据块是连续的。该wait event可能在以下情景中发生:
http://www.askmaclean.com/archives/db-file-sequential-read-wait-event.html
latch free 其实是未获得latch ,而进入latch sleep,见《全面解析9i以后Oracle Latch闩锁原理》
enq:XX 队列锁等待,视乎不同的队列锁有不同的情况:
- 你有多了解Oracle Enqueue lock队列锁机制?
- Oracle队列锁: Enqueue HW
- Oracle队列锁enq:US,Undo Segment
- enq: TX – row lock/index contention、allocate ITL等待事件
- enq: TT – contention等待事件
- Oracle队列锁enq:TS,Temporary Segment (also TableSpace)
- enq: JI – contention等待事件
- enq: US – contention等待事件
- enq: TM – contention等待事件
- enq: RO fast object reuse等待事件
- enq: HW – contention等待事件
free buffer waits:是由于无法找到可用的buffer cache 空闲区域,需要等待DBWR 写入完成引起
- 一般是由于
- 低效的sql
- 过小的buffer cache
- DBWR 工作负荷过量
buffer busy wait/ read by other session 一般以上2个等待事件可以归为一起处理,建议客户都进行监控 。 以上等待时间可以由如下操作引起
- select/select —- read by other session: 由于需要从 数据文件中将数据块读入 buffer cache 中引起,有可能是 大量的 逻辑/物理读 ;或者过小的 buffer cache 引起
- select/update —- buffer busy waits/ read by other session 是由于更新某数据块后 需要在undo 中 重建构建 过去时间的块,有可能伴生 enq:cr-contention 是由于大量的物理读/逻辑读造成。
- update/update —- buffer busy waits 由于更新同一个数据块(非同一行,同一行是enq:TX-contention) 此类问题是热点块造成
- insert/insert —- buffer busy waits 是由于freelist 争用造成,可以将表空间更改为ASSM 管理 或者加大freelist 。
write complete waits :一般此类等待事件是由于 DBWR 将脏数据写入 数据文件,其他进程如果需要修改 buffer cache会引起此等待事件,一般是 I/O 性能问题或者是DBWR 工作负荷过量引起
Wait time 1 Seconds.
control file parallel write:频繁的更新控制文件会造成大量此类等待事件,如日志频繁切换,检查点经常发生,nologging 引起频繁的数据文件更改,I/O 系统性能缓慢。
log file sync:一般此类等待时间是由于 LGWR 进程讲redo log buffer 写入redo log 中发生。如果此类事件频繁发生,可以判断为:
- commit 次数是否过多
- I/O 系统问题
- 重做日志是否不必要被创建
- redo log buffer 是否过大
2-1 Time Model Statistics
Time Model Statistics DB/Inst: ITSCMP/itscmp2 Snaps: 70719-70723 -> Total time in database user-calls (DB Time): 883542.2s -> Statistics including the word "background" measure background process time, and so do not contribute to the DB time statistic -> Ordered by % or DB time desc, Statistic name Statistic Name Time (s) % of DB Time ------------------------------------------ ------------------ ------------ sql execute elapsed time 805,159.7 91.1 sequence load elapsed time 41,159.2 4.7 DB CPU 20,649.1 2.3 parse time elapsed 1,112.8 .1 hard parse elapsed time 995.2 .1 hard parse (sharing criteria) elapsed time 237.3 .0 hard parse (bind mismatch) elapsed time 227.6 .0 connection management call elapsed time 29.7 .0 PL/SQL execution elapsed time 9.2 .0 PL/SQL compilation elapsed time 6.6 .0 failed parse elapsed time 2.0 .0 repeated bind elapsed time 0.4 .0 DB time 883,542.2 background elapsed time 25,439.0 background cpu time 1,980.9 -------------------------------------------------------------
Time Model Statistics几个特别有用的时间指标:
- parse time elapsed、hard parse elapsed time 结合起来看解析是否是主要矛盾,若是则重点是软解析还是硬解析
- sequence load elapsed time sequence序列争用是否是问题焦点
- PL/SQL compilation elapsed time PL/SQL对象编译的耗时
- 注意PL/SQL execution elapsed time 纯耗费在PL/SQL解释器上的时间。不包括花在执行和解析其包含SQL上的时间
- connection management call elapsed time 建立数据库session连接和断开的耗时
- failed parse elapsed time 解析失败,例如由于ORA-4031
- hard parse (sharing criteria) elapsed time 由于无法共享游标造成的硬解析
- hard parse (bind mismatch) elapsed time 由于bind type or bind size 不一致造成的硬解析
注意该时间模型中的指标存在包含关系所以Time Model Statistics加起来超过100%再正常不过
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 (sharing criteria) elapsed time 5) hard parse (bind mismatch) elapsed time 3) failed parse elapsed time 4) failed parse (out of shared memory) 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
2-2 Foreground Wait Class
Foreground Wait Class -> s - second, ms - millisecond - 1000th of a second -> ordered by wait time desc, waits desc -> %Timeouts: value of 0 indicates value was < .5%. Value of null is truly 0 -> Captured Time accounts for 102.7% of Total DB time 883,542.21 (s) -> Total FG Wait Time: 886,957.73 (s) DB CPU time: 20,649.06 (s) Avg %Time Total Wait wait Wait Class Waits -outs Time (s) (ms) %DB time -------------------- ---------------- ----- ---------------- -------- --------- Cluster 9,825,884 1 525,134 53 59.4 Concurrency 688,375 0 113,782 165 12.9 User I/O 34,405,042 0 76,695 2 8.7 Commit 172,193 0 62,776 365 7.1 Application 11,422 0 57,760 5057 6.5 Configuration 19,418 1 48,889 2518 5.5 DB CPU 20,649 2.3 Other 1,757,896 94 924 1 0.1 System I/O 30,165 0 598 20 0.1 Network 171,955,673 0 400 0 0.0 Administrative 2 100 0 101 0.0 ------------------------------------------------------------- select distinct wait_class from v$event_name; WAIT_CLASS ---------------------------------------------------------------- Concurrency User I/O System I/O Administrative Other Configuration Scheduler Cluster Application Queueing Idle Network Commit
- Wait Class: 等待事件的类型,如上查询所示,被分作12个类型。 10.2.0.5有916个等待事件,其中Other类型占622个。
- Waits: 该类型所属等待事件在快照时间内的等待次数
- %Time Out 等待超时的比率, 未 超时次数/waits * 100 (%)
- Total Wait Time: 该类型所属等待事件总的耗时,单位为秒
- Avg Wait(ms) : 该类型所属等待事件的平均单次等待时间,单位为ms ,实际这个指标对commit 和 user i/o 以及system i/o类型有点意义,其他等待类型由于等待事件差异较大所以看平均值的意义较小
- waits / txn: 该类型所属等待事件的等待次数和事务比
Other 类型,遇到该类型等待事件 的话 常见的原因是Oracle Bug或者 网络、I/O存在问题, 一般推荐联系Maclean。
Concurrency 类型 并行争用类型的等待事件, 典型的如 latch: shared pool、latch: library cache、row cache lock、library cache pin/lock
Cluster 类型 为Real Application Cluster RAC环境中的等待事件, 需要注意的是 如果启用了RAC option,那么即使你的集群中只启动了一个实例,那么该实例也可能遇到 Cluster类型的等待事件, 例如gc buffer busy
System I/O 主要是后台进程维护数据库所产生的I/O,例如control file parallel write 、log file parallel write、db file parallel write。
User I/O 主要是前台进程做了一些I/O操作,并不是说后台进程不会有这些等待事件。 典型的如db file sequential/scattered read、direct path read
Configuration 由于配置引起的等待事件, 例如 日志切换的log file switch completion (日志文件 大小/数目 不够),sequence的enq: SQ – contention (Sequence 使用nocache) ; Oracle认为它们是由于配置不当引起的,但实际未必真是这样的配置引起的。
Application 应用造成的等待事件, 例如enq: TM – contention和enq: TX – row lock contention; Oracle认为这是由于应用设计不当造成的等待事件, 但实际这些Application class 等待可能受到 Concurrency、Cluster、System I/O 、User I/O等多种类型等待的影响,例如本来commit只要1ms ,则某一行数据仅被锁定1ms, 但由于commit变慢 从而释放行锁变慢,引发大量的enq: TX – row lock contention等待事件。
Commit 仅log file sync ,log file sync的影响十分广泛,值得我们深入讨论。
Network : 网络类型的等待事件 例如 SQL*Net more data to client 、SQL*Net more data to dblink
Idle 空闲等待事件 ,最为常见的是rdbms ipc message (等待实例内部的ipc通信才干活,即别人告知我有活干,我才干,否则我休息==》Idle), SQL*Net message from client(等待SQL*NET传来信息,否则目前没事干)
2-3 前台等待事件
Foreground Wait Events Snaps: 70719-70723 -> s - second, ms - millisecond - 1000th of a second -> Only events with Total Wait Time (s) >= .001 are shown -> ordered by wait time desc, waits desc (idle events last) -> %Timeouts: value of 0 indicates value was < .5%. Value of null is truly 0 Avg %Time Total Wait wait Waits % DB Event Waits -outs Time (s) (ms) /txn time -------------------------- ------------ ----- ---------- ------- -------- ------ gc buffer busy acquire 3,274,352 3 303,088 93 13.3 34.3 gc buffer busy release 387,673 2 128,114 330 1.6 14.5 enq: TX - index contention 193,918 0 97,375 502 0.8 11.0 cell single block physical 30,738,730 0 63,606 2 124.8 7.2 log file sync 172,193 0 62,776 365 0.7 7.1 gc current block busy 146,154 0 53,027 363 0.6 6.0 enq: TM - contention 1,060 0 47,228 44555 0.0 5.3 enq: SQ - contention 17,431 0 35,683 2047 0.1 4.0 gc cr block busy 105,204 0 33,746 321 0.4 3.8 buffer busy waits 279,721 0 12,646 45 1.1 1.4 enq: HW - contention 1,201 3 12,192 10151 0.0 1.4 enq: TX - row lock content 9,231 0 10,482 1135 0.0 1.2 cell multiblock physical r 247,903 0 6,547 26 1.0 .7
Foreground Wait Events 前台等待事件,数据主要来源于DBA_HIST_SYSTEM_EVENT
Event 等待事件名字
Waits 该等待事件在快照时间内等待的次数
%Timeouts : 每一个等待事件有其超时的设置,例如buffer busy waits 一般为3秒, Write Complete Waits的 timeout为1秒,如果等待事件 单次等待达到timeout的时间,则会进入下一次该等待事件
Total Wait Time 该等待事件 总的消耗的时间 ,单位为秒
Avg wait(ms): 该等待事件的单次平均等待时间,单位为毫秒
Waits/Txn: 该等待事件的等待次数和事务比
2-4 后台等待事件
Background Wait Events Snaps: 70719-70723 -> ordered by wait time desc, waits desc (idle events last) -> Only events with Total Wait Time (s) >= .001 are shown -> %Timeouts: value of 0 indicates value was < .5%. Value of null is truly 0 Avg %Time Total Wait wait Waits % bg Event Waits -outs Time (s) (ms) /txn time -------------------------- ------------ ----- ---------- ------- -------- ------ db file parallel write 90,979 0 7,831 86 0.4 30.8 gcs log flush sync 4,756,076 6 4,714 1 19.3 18.5 enq: CF - contention 2,123 40 4,038 1902 0.0 15.9 control file sequential re 90,227 0 2,380 26 0.4 9.4 log file parallel write 108,383 0 1,723 16 0.4 6.8 control file parallel writ 4,812 0 988 205 0.0 3.9 Disk file operations I/O 26,216 0 731 28 0.1 2.9 flashback log file write 9,870 0 720 73 0.0 2.8 LNS wait on SENDREQ 202,747 0 600 3 0.8 2.4 ASM file metadata operatio 15,801 0 344 22 0.1 1.4 cell single block physical 39,283 0 341 9 0.2 1.3 LGWR-LNS wait on channel 183,443 18 203 1 0.7 .8 gc current block busy 122 0 132 1082 0.0 .5 gc buffer busy release 60 12 127 2113 0.0 .5 Parameter File I/O 592 0 116 195 0.0 .5 log file sequential read 1,804 0 104 58 0.0 .4
Background Wait Events 后台等待事件, 数据主要来源于DBA_HIST_BG_EVENT_SUMMARY
Event 等待事件名字
Waits 该等待事件在快照时间内等待的次数
%Timeouts : 每一个等待事件有其超时的设置,例如buffer busy waits 一般为3秒, Write Complete Waits的 timeout为1秒,如果等待事件 单次等待达到timeout的时间,则会进入下一次该等待事件
Total Wait Time 该等待事件 总的消耗的时间 ,单位为秒
Avg wait(ms): 该等待事件的单次平均等待时间,单位为毫秒
Waits/Txn: 该等待事件的等待次数和事务比
2-5 Operating System Statistics
Operating System Statistics Snaps: 70719-70723 TIME statistic values are diffed. All others display actual values. End Value is displayed if different -> ordered by statistic type (CPU Use, Virtual Memory, Hardware Config), Name Statistic Value End Value ------------------------- ---------------------- ---------------- BUSY_TIME 2,894,855 IDLE_TIME 5,568,240 IOWAIT_TIME 18,973 SYS_TIME 602,532 USER_TIME 2,090,082 LOAD 8 13 VM_IN_BYTES 0 VM_OUT_BYTES 0 PHYSICAL_MEMORY_BYTES 101,221,343,232 NUM_CPUS 24 NUM_CPU_CORES 12 NUM_CPU_SOCKETS 2 GLOBAL_RECEIVE_SIZE_MAX 4,194,304 GLOBAL_SEND_SIZE_MAX 2,097,152 TCP_RECEIVE_SIZE_DEFAULT 87,380 TCP_RECEIVE_SIZE_MAX 4,194,304 TCP_RECEIVE_SIZE_MIN 4,096 TCP_SEND_SIZE_DEFAULT 16,384 TCP_SEND_SIZE_MAX 4,194,304 TCP_SEND_SIZE_MIN 4,096 -------------------------------------------------------------
Operating System Statistics 操作系统统计信息
数据来源于V$OSSTAT / DBA_HIST_OSSTAT,, TIME相关的指标单位均为百分之一秒
统计项 | 描述 |
NUM_CPU_SOCKETS | 物理CPU的数目 |
NUM_CPU_CORES | CPU的核数 |
NUM_CPUS | 逻辑CPU的数目 |
SYS_TIME | 在内核态被消耗掉的CPU时间片,单位为百分之一秒 |
USER_TIME | 在用户态被消耗掉的CPU时间片,单位为百分之一秒 |
BUSY_TIME | Busy_Time=SYS_TIME+USER_TIME 消耗的CPU时间片,单位为百分之一秒 |
AVG_BUSY_TIME | AVG_BUSY_TIME= BUSY_TIME/NUM_CPUS |
IDLE_TIME | 空闲的CPU时间片,单位为百分之一秒 |
所有CPU所能提供总的时间片 | BUSY_TIME + IDLE_TIME = ELAPSED_TIME * CPU_COUNT |
OS_CPU_WAIT_TIME | 进程等OS调度的时间,cpu queuing |
VM_IN_BYTES | 换入页的字节数 |
VM_OUT_BYTES | 换出页的字节数,部分版本下并不准确,例如Bug 11712010 Abstract: VIRTUAL MEMORY PAGING ON 11.2.0.2 DATABASES,仅供参考 |
IOWAIT_TIME | 所有CPU花费在等待I/O完成上的时间 单位为百分之一秒 |
RSRC_MGR_CPU_WAIT_TIME | 是指当resource manager控制CPU调度时,需要控制对应进程暂时不使用CPU而进程到内部运行队列中,以保证该进程对应的consumer group(消费组)没有消耗比指定resource manager指令更多的CPU。RSRC_MGR_CPU_WAIT_TIME指等在内部运行队列上的时间,在等待时不消耗CPU |
2-6 Service Statistcs
Service Statistics Snaps: 70719-70723 -> ordered by DB Time Physical Logical Service Name DB Time (s) DB CPU (s) Reads (K) Reads (K) ---------------------------- ------------ ------------ ------------ ------------ itms-contentmasterdb-prod 897,099 20,618 35,668 1,958,580 SYS$USERS 4,312 189 5,957 13,333 itmscmp 1,941 121 14,949 18,187 itscmp 331 20 114 218 itscmp_dgmgrl 121 1 0 0 SYS$BACKGROUND 0 0 142 30,022 ITSCMP1_PR 0 0 0 0 its-reference-prod 0 0 0 0 itscmpXDB 0 0 0 0
按照Service Name来分组时间模型和 物理、逻辑读取, 部分数据来源于 WRH$_SERVICE_NAME;
Service Name 对应的服务名 (v$services), SYS$BACKGROUND代表后台进程, SYS$USERS一般是系统用户登录
DB TIME (s): 本服务名所消耗的DB TIME时间,单位为秒
DB CPU(s): 本服务名所消耗的DB CPU 时间,单位为秒
Physical Reads : 本服务名所消耗的物理读
Logical Reads : 本服务所消耗的逻辑读
2-7 Service Wait Class Stats
Service Wait Class Stats Snaps: 70719-70723 -> Wait Class info for services in the Service Statistics section. -> Total Waits and Time Waited displayed for the following wait classes: User I/O, Concurrency, Administrative, Network -> Time Waited (Wt Time) in seconds Service Name ---------------------------------------------------------------- User I/O User I/O Concurcy Concurcy Admin Admin Network Network Total Wts Wt Time Total Wts Wt Time Total Wts Wt Time Total Wts Wt Time --------- --------- --------- --------- --------- --------- --------- --------- itms-contentmasterdb-prod 33321670 71443 678373 113759 0 0 1.718E+08 127 SYS$USERS 173233 3656 6738 30 2 0 72674 3 itmscmp 676773 1319 1831 0 0 0 2216 0 itscmp 219577 236 1093 0 0 0 18112 0 itscmp_dgmgrl 34 0 8 0 0 0 9 0 SYS$BACKGROUND 71940 1300 320677 56 0 0 442252 872 -------------------------------------------------------------
- User I/O Total Wts : 对应该服务名下 用户I/O类等待的总的次数
- User I/O Wt Time : 对应该服务名下 用户I/O累等待的总时间,单位为 1/100秒
- Concurcy Total Wts: 对应该服务名下 Concurrency 类型等待的总次数
- Concurcy Wt Time :对应该服务名下 Concurrency 类型等待的总时间, 单位为 1/100秒
- Admin Total Wts: 对应该服务名下Admin 类等待的总次数
- Admin Wt Time: 对应该服务名下Admin类等待的总时间,单位为 1/100秒
- Network Total Wts : 对应服务名下Network类等待的总次数
- Network Wt Time: 对应服务名下Network类等待的总事件, 单位为 1/100秒
2-8 Host CPU
Host CPU (CPUs: 24 Cores: 12 Sockets: 2) ~~~~~~~~ Load Average Begin End %User %System %WIO %Idle --------- --------- --------- --------- --------- --------- 8.41 12.84 24.7 7.1 0.2 65.8
“Load Average” begin/end值代表每个CPU的大致运行队列大小。上例中快照开始到结束,平均 CPU负载增加了;与《2-5 Operating System Statistics》中的LOAD相呼应。
%User+%System=> 总的CPU使用率,在这里是31.8%
Elapsed Time * NUM_CPUS * CPU utilization= 60.23 (mins) * 24 * 31.8% = 459.67536 mins=Busy Time
2-8 Instance CPU
Instance CPU ~~~~~~~~~~~~ % of total CPU for Instance: 26.7 % of busy CPU for Instance: 78.2 %DB time waiting for CPU - Resource Mgr: 0.0
%Total CPU,该实例所使用的CPU占总CPU的比例 % of total CPU for Instance
%Busy CPU,该实例所使用的Cpu占总的被使用CPU的比例 % of busy CPU for Instance
例如共4个逻辑CPU,其中3个被完全使用,3个中的1个完全被该实例使用,则%Total CPU= ¼ =25%,而%Busy CPU= 1/3= 33%
当CPU高时一般看%Busy CPU可以确定CPU到底是否是本实例消耗的,还是主机上其他程序
% of busy CPU for Instance= (DB CPU+ background cpu time) / (BUSY_TIME /100)= (20,649.1 + 1,980.9)/ (2,894,855 /100)= 78.17%
% of Total CPU for Instance = ( DB CPU+ background cpu time)/( BUSY_TIME+IDLE_TIME/100) = (20,649.1 + 1,980.9)/ ((2,894,855+5,568,240) /100) = 26.73%
%DB time waiting for CPU (Resource Manager)= (RSRC_MGR_CPU_WAIT_TIME/100)/DB TIME
3 TOP SQL
TOP SQL 的数据部分来源于 dba_hist_sqlstat
3-1 SQL ordered by Elapsed Time ,按照SQL消耗的时间来排列TOP SQL
SQL ordered by Elapsed Time Snaps: 70719-70723 -> Resources reported for PL/SQL code includes the resources used by all SQL statements called by the code. -> % Total DB Time is the Elapsed Time of the SQL statement divided into the Total Database Time multiplied by 100 -> %Total - Elapsed Time as a percentage of Total DB time -> %CPU - CPU Time as a percentage of Elapsed Time -> %IO - User I/O Time as a percentage of Elapsed Time -> Captured SQL account for 53.9% of Total DB Time (s): 883,542 -> Captured PL/SQL account for 0.5% of Total DB Time (s): 883,542 Elapsed Elapsed Time Time (s) Executions per Exec (s) %Total %CPU %IO SQL Id ---------------- -------------- ------------- ------ ------ ------ ------------- 181,411.3 38,848 4.67 20.5 .0 .1 g0yc9szpuu068
注意对于PL/SQL,SQL Statistics不仅会体现该PL/SQL的执行情况,还会包括该PL/SQL包含的SQL语句的情况。如上例一个TOP PL/SQL执行了448s,而这448s中绝大多数是这个PL/SQL下的一个SQL执行500次耗费的。
则该TOP PL/SQL和TOP SQL都上榜,一个执行一次耗时448s,一个执行500次耗时448s。 如此情况则Elapsed Time加起来可能超过100%的Elapsed Time,这是正常的。
对于鹤立鸡群的SQL很有必要一探究竟,跑个@?/rdbms/admin/awrsqrpt看看吧!
Elapsed Time (s): 该SQL累计运行所消耗的时间,
Executions : 该SQL在快照时间内 总计运行的次数 ; 注意, 对于在快照时间内还没有执行完的SQL 不计为1一次,所以如果看到executions=0而 又是TOP SQL,则很有可能是因为该SQL 运行较旧还没执行完,需要特别关注一下。
Elapsed Time per Exec (s):平均每次执行该SQL耗费的时间 , 对于OLTP类型的SELECT/INSERT/UPDATE/DELETE而言平均单次执行时间应当非常短,如0.1秒 或者更短才能满足其业务需求,如果这类轻微的OLTP操作单次也要几秒钟的话,是无法满足对外业务的需求的; 例如你在ATM上提款,并不仅仅是对你的账务库的简单UPDATE,而需要在类似风险控制的前置系统中记录你本次的流水操作记录,实际取一次钱可能要有几十乃至上百个OLTP类型的语句被执行,但它们应当都是十分快速的操作; 如果这些操作也变得很慢,则会出现大量事务阻塞,系统负载升高,DB TIME急剧上升的现象。 对于OLTP数据库而言 如果执行计划稳定,那么这些OLTP操作的性能应当是铁板钉钉的,但是一旦某个因素 发生变化,例如存储的明显变慢、内存换页的大量出现时 则上述的这些transaction操作很可能成数倍到几十倍的变慢,这将让此事务系统短期内不可用。
对于维护操作,例如加载或清除数据,大的跑批次、报表而言 Elapsed Time per Exec (s)高一些是正常的。
%Total 该SQL所消耗的时间占总的DB Time的百分比, 即 (SQL Elapsed Time / Total DB TIME)
% CPU 该SQL 所消耗的CPU 时间 占 该SQL消耗的时间里的比例, 即 (SQL CPU Time / SQL Elapsed Time) ,该指标说明了该语句是否是CPU敏感的
%IO 该SQL 所消耗的I/O 时间 占 该SQL消耗的时间里的比例, 即(SQL I/O Time/SQL Elapsed Time) ,该指标说明了该语句是否是I/O敏感的
SQL Id : 通过计算SQL 文本获得的SQL_ID ,不同的SQL文本必然有不同的SQL_ID, 对于10g~11g而言 只要SQL文本不变那么在数据库之间 该SQL 对应的SQL_ID应当不不变的, 12c中修改了SQL_ID的计算方法
Captured SQL account for 53.9% of Total DB Time (s) 对于不绑定变量的应用来说Top SQL有可能失准,所以要参考本项
3-2 SQL ordered by CPU Time
SQL ordered by CPU Time Snaps: 70719-70723 -> Resources reported for PL/SQL code includes the resources used by all SQL statements called by the code. -> %Total - CPU Time as a percentage of Total DB CPU -> %CPU - CPU Time as a percentage of Elapsed Time -> %IO - User I/O Time as a percentage of Elapsed Time -> Captured SQL account for 34.9% of Total CPU Time (s): 20,649 -> Captured PL/SQL account for 0.5% of Total CPU Time (s): 20,649 CPU CPU per Elapsed Time (s) Executions Exec (s) %Total Time (s) %CPU %IO SQL Id ---------- ------------ ---------- ------ ---------- ------ ------ ------------- 1,545.0 1,864,424 0.00 7.5 4,687.8 33.0 65.7 8g6a701j83c8q Module: MZIndexer SELECT t0.BOOLEAN_VALUE, t0.CLASS_CODE, t0.CREATED, t0.END_DATE, t0.PRODUCT_ATTR IBUTE_ID, t0.LAST_MODIFIED, t0.OVERRIDE_FLAG, t0.PRICE, t0.PRODUCT_ATTRIBUTE_TYP E_ID, t0.PRODUCT_ID, t0.PRODUCT_PUB_RELEASE_TYPE_ID, t0.PRODUCT_VOD_TYPE_ID, t0. SAP_PRODUCT_ID, t0.START_DATE, t0.STRING_VALUE FROM mz_product_attribute t0 WHER
CPU TIME : 该SQL 在快照时间内累计执行所消耗的CPU 时间片,单位为s
Executions : 该SQL在快照时间内累计执行的次数
CPU per Exec (s) :该SQL 平均单次执行所消耗的CPU时间 , 即 ( SQL CPU TIME / SQL Executions )
%Total : 该SQL 累计消耗的CPU时间 占 该时段总的 DB CPU的比例, 即 ( SQL CPU TIME / Total DB CPU)
% CPU 该SQL 所消耗的CPU 时间 占 该SQL消耗的时间里的比例, 即 (SQL CPU Time / SQL Elapsed Time) ,该指标说明了该语句是否是CPU敏感的
%IO 该SQL 所消耗的I/O 时间 占 该SQL消耗的时间里的比例, 即(SQL I/O Time/SQL Elapsed Time) ,该指标说明了该语句是否是I/O敏感的
3-3 Buffer Gets SQL ordered by Gets
SQL ordered by Gets DB/Inst: ITSCMP/itscmp2 Snaps: 70719-70723 -> Resources reported for PL/SQL code includes the resources used by all SQL statements called by the code. -> %Total - Buffer Gets as a percentage of Total Buffer Gets -> %CPU - CPU Time as a percentage of Elapsed Time -> %IO - User I/O Time as a percentage of Elapsed Time -> Total Buffer Gets: 2,021,476,421 -> Captured SQL account for 68.2% of Total Buffer Gets Elapsed Gets Executions per Exec %Total Time (s) %CPU %IO SQL Id ----------- ----------- ------------ ------ ---------- ------ ------ ----------- 4.61155E+08 1,864,424 247.3 22.8 4,687.8 33.0 65.7 8g6a701j83c
注意 buffer gets 逻辑读是消耗CPU TIME的重要源泉, 但并不是说消耗CPU TIME的只有buffer gets。 大多数情况下 SQL order by CPU TIME 和 SQL order by buffers gets 2个部分的TOP SQL 及其排列顺序都是一样的,此种情况说明消耗最多buffer gets的 就是消耗最多CPU 的SQL ,如果我们希望降低系统的CPU使用率,那么只需要调优SQL 降低buffer gets 即可。
但也并不是100%的情况都是如此, CPU TIME的消耗者 还包括 函数运算、PL/SQL 控制、Latch /Mutex 的Spin等等, 所以SQL order by CPU TIME 和 SQL order by buffers gets 2个部分的TOP SQL 完全不一样也是有可能的, 需要因地制宜来探究到底是什么问题导致的High CPU,进而裁度解决之道。
Buffer Gets : 该SQL在快照时间内累计运行所消耗的buffer gets,包括了consistent read 和 current read
Executions : 该SQL在快照时间内累计执行的次数
Gets per Exec : 该SQL平均单次的buffer gets , 对于事务型transaction操作而言 一般该单次buffer gets小于2000
% Total 该SQL 累计运行所消耗的buffer gets占 总的db buffer gets的比率, (SQL buffer gets / DB total buffer gets)
3-4 Physical Reads SQL ordered by Reads
SQL ordered by Reads DB/Inst: ITSCMP/itscmp2 Snaps: 70719-70723 -> %Total - Physical Reads as a percentage of Total Disk Reads -> %CPU - CPU Time as a percentage of Elapsed Time -> %IO - User I/O Time as a percentage of Elapsed Time -> Total Disk Reads: 56,839,035 -> Captured SQL account for 34.0% of Total Physical Reads Elapsed Reads Executions per Exec %Total Time (s) %CPU %IO SQL Id ----------- ----------- ---------- ------ ---------- ------ ------ ------------- 9,006,163 1 9.0062E+06 15.8 720.9 5.9 80.9 4g36tmp70h185
Physical reads : 该SQL累计运行所消耗的物理读
Executions : 该SQL在快照时间内累计执行的次数
Reads per Exec : 该SQL 单次运行所消耗的物理读, (SQL Physical reads/Executions) , 对于OLTP transaction 类型的操作而言单次一般不超过100
%Total : 该SQL 累计消耗的物理读 占 该时段总的 物理读的比例, 即 ( SQL physical read / Total DB physical read )
3-5 Executions SQL ordered by Executions
SQL ordered by Executions Snaps: 70719-70723 -> %CPU - CPU Time as a percentage of Elapsed Time -> %IO - User I/O Time as a percentage of Elapsed Time -> Total Executions: 48,078,147 -> Captured SQL account for 50.4% of Total Elapsed Executions Rows Processed Rows per Exec Time (s) %CPU %IO SQL Id ------------ --------------- -------------- ---------- ------ ------ ----------- 6,327,963 11,249,645 1.8 590.5 47.8 52.7 1avv7759j8r
按照 执行次数来排序的话,也是性能报告对比时一个重要的参考因素,因为如果TOP SQL的执行次数有明显的增长,那么 性能问题的出现也是意料之中的事情了。 当然执行次数最多的,未必便是对性能影响最大的TOP SQL
Executions : 该SQL在快照时间内累计执行的次数
Rows Processed: 该SQL在快照时间内累计执行所处理的总行数
Rows per Exec: SQL平均单次执行所处理的行数, 这个指标在诊断一些 数据问题造成的SQL性能问题时很有用
3-6 Parse Calls SQL ordered by Parse Calls
SQL ordered by Parse Calls Snaps: 70719-70723 -> Total Parse Calls: 2,160,124 -> Captured SQL account for 58.3% of Total % Total Parse Calls Executions Parses SQL Id ------------ ------------ --------- ------------- 496,475 577,357 22.98 d07gaa3wntdff
Parse Calls : 解析调用次数, 与上文的 Load Profile中的Parse 数一样 包括 软解析soft parse和硬解析hard parse
Executions : 该SQL在快照时间内累计执行的次数
%Total Parses : 本SQL 解析调用次数 占 该时段数据库总解析次数的比率, 为 (SQL Parse Calls / Total DB Parse Calls)
3-7 SQL ordered by Sharable Memory
SQL ordered by Sharable Memory Snaps: 70719-70723 -> Only Statements with Sharable Memory greater than 1048576 are displayed Sharable Mem (b) Executions % Total SQL Id ---------------- ------------ -------- ------------- 8,468,359 39 0.08 au89sasqfb2yn Module: MZContentBridge SELECT t0.ASPECT_RATIO, t0.CREATED, t0.FILE_EXTENSION, t0.HEIGHT, t0.VIDEO_FILE_ DIMENSIONS_ID, t0.LAST_MODIFIED, t0.NAME, t0.WIDTH FROM MZ_VIDEO_FILE_DIMENSIONS t0 WHERE (t0.HEIGHT = :1 AND t0.WIDTH = :2 )
SQL ordered by Sharable Memory , 一般该部分仅列出Sharable Mem (b)为1 MB以上的SQL 对象 (Only Statements with Sharable Memory greater than 1048576 are displayed) 数据来源是 DBA_HIST_SQLSTAT.SHARABLE_MEM
Shareable Mem(b): SQL 对象所占用的共享内存使用量
Executions : 该SQL在快照时间内累计执行的次数
%Total : 该SQL 对象锁占共享内存 占总的共享内存的比率
3-8 SQL ordered by Version Count
Version Count Oracle中的执行计划可以是多版本的,即对于同一个SQL语句有多个不同版本的执行计划,这些执行计划又称作子游标, 而一个SQL语句的文本可以称作一个父游标。 一个父游标对应多个子游标,产生不同子游标的原因是 SQL在被执行时无法共享之前已经生成的子游标, 原因是多种多样的,例如 在本session中做了一个优化器参数的修改 例如optimizer_index_cost_adj 从100 修改到99,则本session的优化环境optimizer env将不同于之前的子游标生成环境,这样就需要生成一个新的子游标,例如:
SQL> create table emp as select * from scott.emp; Table created. SQL> select * from emp where empno=1; no rows selected SQL> select /*+ MACLEAN */ * from emp where empno=1; no rows selected SQL> select SQL_ID,version_count from V$SQLAREA WHERE SQL_TEXT like ‘%MACLEAN%‘ and SQL_TEXT not like ‘%like%‘; SQL_ID VERSION_COUNT ------------- ------------- bxnnm7z1qmg26 1 SQL> select count(*) from v$SQL where SQL_ID=‘bxnnm7z1qmg26‘; COUNT(*) ---------- 1 SQL> alter session set optimizer_index_cost_adj=99; Session altered. SQL> select /*+ MACLEAN */ * from emp where empno=1; no rows selected SQL> select SQL_ID,version_count from V$SQLAREA WHERE SQL_TEXT like ‘%MACLEAN%‘ and SQL_TEXT not like ‘%like%‘; SQL_ID VERSION_COUNT ------------- ------------- bxnnm7z1qmg26 2 SQL> select count(*) from v$SQL where SQL_ID=‘bxnnm7z1qmg26‘; COUNT(*) ---------- 2 SQL> select child_number ,OPTIMIZER_ENV_HASH_VALUE,PLAN_HASH_VALUE from v$SQL where SQL_ID=‘bxnnm7z1qmg26‘; CHILD_NUMBER OPTIMIZER_ENV_HASH_VALUE PLAN_HASH_VALUE ------------ ------------------------ --------------- 0 3704128740 3956160932 1 3636478958 3956160932
可以看到上述 演示中修改optimizer_index_cost_adj=99 导致CBO 优化器的优化环境发生变化, 表现为不同的OPTIMIZER_ENV_HASH_VALUE,之后生成了2个子游标,但是这2个子游标的PLAN_HASH_VALUE同为3956160932,则说明了虽然是不同的子游标但实际子游标里包含了的执行计划是一样的; 所以请注意 任何一个优化环境的变化 (V$SQL_SHARED_CURSOR)以及相关衍生的BUG 都可能导致子游标无法共享,虽然子游标无法共享但这些子游标扔可能包含完全一样的执行计划,这往往是一种浪费。
注意V$SQLAREA.VERSION_COUNT 未必等于select count(*) FROM V$SQL WHERE SQL_ID=” ,即 V$SQLAREA.VERSION_COUNT 显示的子游标数目 未必等于当前实例中还存有的子游标数目, 由于shared pool aged out算法和其他一些可能导致游标失效的原因存在,所以子游标被清理掉是很常见的事情。 V$SQLAREA.VERSION_COUNT只是一个计数器,它告诉我们曾经生成了多少个child cursor,但不保证这些child 都还在shared pool里面。
此外可以通过v$SQL的child_number字段来分析该问题,如果child_number存在跳号则也说明了部分child被清理了。
子游标过多的影响, 当子游标过多(例如超过3000个时),进程需要去扫描长长的子游标列表child cursor list以找到一个合适的子游标child cursor,进而导致cursor sharing 性能问题 现大量的Cursor: Mutex S 和 library cache lock等待事件。
关于子游标的数量控制,可以参考《11gR2游标共享新特性带来的一些问题以及_cursor_features_enabled、_cursor_obsolete_threshold和106001 event》。
Executions : 该SQL在快照时间内累计执行的次数
Hash Value : 共享SQL 的哈希值
Only Statements with Version Count greater than 20 are displayed 注意该环节仅列出version count > 20的语句
3-9 Cluster Wait Time SQL ordered by Cluster Wait Time
SQL ordered by Cluster Wait Time DB/Inst: ITSCMP/itscmp2 Snaps: 70719-70723 -> %Total - Cluster Time as a percentage of Total Cluster Wait Time -> %Clu - Cluster Time as a percentage of Elapsed Time -> %CPU - CPU Time as a percentage of Elapsed Time -> %IO - User I/O Time as a percentage of Elapsed Time -> Only SQL with Cluster Wait Time > .005 seconds is reported -> Total Cluster Wait Time (s): 525,480 -> Captured SQL account for 57.2% of Total Cluster Elapsed Wait Time (s) Executions %Total Time(s) %Clu %CPU %IO SQL Id -------------- ------------ ------ ---------- ------ ------ ------ ------------- 132,639.3 38,848 25.2 181,411.3 73.1 .0 .1 g0yc9szpuu068
Only SQL with Cluster Wait Time > .005 seconds is reported 这个环节仅仅列出Cluster Wait Time > 0.005 s的SQL
该环节的数据主要来源 于 DBA_HIST_SQLSTAT.CLWAIT_DELTA Delta value of cluster wait time
Cluster Wait Time : 该SQL语句累计执行过程中等待在集群等待上的时间,单位为秒, 你可以理解为 当一个SQL 执行过程中遇到了gc buffer busy、gc cr multi block request 之类的Cluster等待,则这些等待消耗的时间全部算在 Cluster Wait Time里。
Executions : 该SQL在快照时间内累计执行的次数
%Total: 该SQL所消耗的Cluster Wait time 占 总的Cluster Wait time的比率, 为(SQL cluster wait time / DB total cluster Wait Time)
%Clu: 该SQL所消耗的Cluster Wait time 占该SQL 总的耗时的比率,为(SQL cluster wait time / SQL elapsed Time),该指标说明了该语句是否是集群等待敏感的
% CPU 该SQL 所消耗的CPU 时间 占 该SQL消耗的时间里的比例, 即 (SQL CPU Time / SQL Elapsed Time) ,该指标说明了该语句是否是CPU敏感的
%IO 该SQL 所消耗的I/O 时间 占 该SQL消耗的时间里的比例, 即(SQL I/O Time/SQL Elapsed Time) ,该指标说明了该语句是否是I/O敏感的
4 Instance Activity Stats
Instance Activity Stats DB/Inst: ITSCMP/itscmp2 Snaps: 70719-70723 -> Ordered by statistic name Statistic Total per Second per Trans -------------------------------- ------------------ -------------- ------------- Batched IO (bound) vector count 450,449 124.6 1.8 Batched IO (full) vector count 5,485 1.5 0.0 Batched IO (space) vector count 1,467 0.4 0.0 Batched IO block miss count 4,119,070 1,139.7 16.7 Batched IO buffer defrag count 39,710 11.0 0.2 Batched IO double miss count 297,357 82.3 1.2 Batched IO same unit count 1,710,492 473.3 7.0 Batched IO single block count 329,521 91.2 1.3 Batched IO slow jump count 47,104 13.0 0.2 Batched IO vector block count 2,069,852 572.7 8.4 Batched IO vector read count 262,161 72.5 1.1 Block Cleanout Optim referenced 37,574 10.4 0.2 CCursor + sql area evicted 1,457 0.4 0.0 ...............
Instance Activity Stats 的数据来自于 DBA_HIST_SYSSTAT,DBA_HIST_SYSSTAT来自于V$SYSSTAT。
这里每一个指标都代表一种数据库行为的活跃度,例如redo size 是指生成redo的量,sorts (disk) 是指磁盘排序的次数,table scans (direct read) 是指直接路径扫描表的次数。
虽然这些指标均只有Total、per Second每秒、 per Trans每事务 三个维度,但对诊断问题十分有用。
我们来举几个例子:
1、 例如当 Top Event 中存在direct path read为Top 等待事件, 则需要分清楚是对普通堆表的direct read还是由于大量LOB读造成的direct path read, 这个问题可以借助 table scans (direct read)、table scans (long tables)、physical reads direct 、physical reads direct (lob) 、physical reads direct temporary几个指标来分析, 假设 physical reads direct >> 远大于 physical reads direct (lob)+physical reads direct temporary , 且有较大的table scans (direct read)、table scans (long tables) (注意这2个指标代表的是 扫描表的次数 不同于上面的phsical reads 的单位为 块数*次数), 则说明了是 大表扫描引起的direct path read。
2、 例如当 Top Event中存在enq Tx:index contention等待事件, 则需要分析root node splits 、branch node splits 、leaf node 90-10 splits 、leaf node splits 、failed probes on index block rec 几个指标,具体可以见文档《Oracle索引块分裂split信息汇总》
3、系统出现IO类型的等待事件为TOp Five 例如 db file sequential/scattered read ,我们需要通过AWR来获得系统IO吞吐量和IOPS:
physical read bytes 主要是应用造成的物理读取(Total size in bytes of all disk reads by application activity (and not other instance activity) only.) 而physical read total bytes则包括了 rman备份恢复 和后台维护任务所涉及的物理读字节数,所以我们在研究IO负载时一般参考 physical read total bytes;以下4对指标均存在上述的关系
physical read bytes | physical read total bytes | 物理读的吞吐量/秒 |
physical read IO requests | physical read total IO requests | 物理读的IOPS |
physical write bytes | physical write total bytes | 物理写的吞吐量/秒 |
physical write IO requests | physical write total IO requests | 物理写的IOPS |
总的物理吞吐量/秒=physical read total bytes+physical write total bytes
总的物理IOPS= physical read total IO requests+ physical write total IO requests
IO的主要指标 吞吐量、IOPS和延迟 均可以从AWR中获得了, IO延迟的信息可以从 User I/O的Wait Class Avg Wait time获得,也可以参考11g出现的IOStat by Function summary
Instance Activity Stats有大量的指标,但是对于这些指标的介绍 没有那一份文档有完整详尽的描述,即便在Oracle原厂内部要没有(或者是Maclean没找到),实际是开发人员要引入某一个Activity Stats是比较容易的,并不像申请引入一个新后台进程那样麻烦,Oracle对于新版本中新后台进程的引入有严格的要求,但Activity Stats却很容易,往往一个one-off patch中就可以引入了,实际上Activity Stats在源代码层仅仅是一些计数器。’
较为基础的statistics,大家可以参考官方文档的Statistics Descriptions描述,地址在这里。
对于深入的指标 例如 “Batched IO (space) vector count”这种由于某些新特性被引入的,一般没有很详细的材料,需要到源代码中去阅读相关模块才能总结其用途,对于这个工作一般原厂是很延迟去完成的,所以没有一个完整的列表。 如果大家有对此的疑问,请去t.askmaclean.com 发一个帖子提问。
Instance Activity Stats - Absolute Values Snaps: 7071 -> Statistics with absolute values (should not be diffed) Statistic Begin Value End Value -------------------------------- --------------- --------------- session pga memory max 1.157882826E+12 1.154290304E+12 session cursor cache count 157,042,373 157,083,136 session uga memory 5.496429019E+14 5.496775467E+14 opened cursors current 268,916 265,694 workarea memory allocated 827,704 837,487 logons current 2,609 2,613 session uga memory max 1.749481584E+13 1.749737418E+13 session pga memory 4.150306913E+11 4.150008177E+11
Instance Activity Stats – Absolute Values是显示快照 起点 和终点的一些指标的绝对值
- logon current 当前时间点的登录数
- opened cursors current 当前打开的游标数
- session cursor cache count 当前存在的session缓存游标数
Instance Activity Stats - Thread ActivityDB/Inst: G10R25/G10R25 Snaps: 3663-3 -> Statistics identified by ‘(derived)‘ come from sources other than SYSSTAT Statistic Total per Hour -------------------------------- ------------------ --------- log switches (derived) 17 2,326.47
log switches (derived) 日志切换次数 , 见 《理想的在线重做日志切换时间是多长?》
5 IO 统计
5-1 Tablespace IO Stats 基于表空间分组的IO信息
Tablespace IO Stats DB/Inst: ITSCMP/itscmp2 Snaps: 70719-70723 -> 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) -------------- ------- ------- ------- ------------ -------- ---------- ------- DATA_TS 17,349,398 4,801 2.3 1.5 141,077 39 4,083,704 5.8 INDEX_TS 9,193,122 2,544 2.0 1.0 238,563 66 3,158,187 46.1 UNDOTBS1 1,582,659 438 0.7 1.0 2 0 12,431 69.0
reads : 指 该表空间上发生的物理读的次数(单位不是块,而是次数)
Av Reads/s : 指该表空间上平均每秒的物理读次数 (单位不是块,而是次数)
Av Rd(ms): 指该表空间上每次读的平均读取延迟
Av Blks/Rd: 指该表空间上平均每次读取的块数目,因为一次物理读可以读多个数据块;如果Av Blks/Rd>>1 则可能系统有较多db file scattered read 可能是诊断FULL TABLE SCAN或FAST FULL INDEX SCAN,需要关注table scans (long tables) 和index fast full scans (full) 2个指标
Writes : 该表空间上发生的物理写的次数 ; 对于那些Writes总是等于0的表空间 不妨了解下是否数据为只读,如果是可以通过read only tablespace来解决 RAC中的一些性能问题。
Av Writes/s : 指该表空间上平均每秒的物理写次数
buffer Waits: 该表空间上发生buffer busy waits和read by other session的次数( 9i中buffer busy waits包含了read by other session)。
Av Buf Wt(ms): 该表空间上发生buffer Waits的平均等待时间,单位为ms
5-2 File I/O
File IO Stats Snaps: 70719-70723 -> ordered by Tablespace, File Tablespace Filename ------------------------ ---------------------------------------------------- Av Av Av Av Buffer Av Buf Reads Reads/s Rd(ms) Blks/Rd Writes Writes/s Waits Wt(ms) -------------- ------- ------- ------- ------------ -------- ---------- ------- AMG_ALBUM_IDX_TS +DATA/itscmp/plugged/data2/amg_album_idx_ts01.dbf 23,298 6 0.6 1.0 2 0 0 0.0 AMG_ALBUM_IDX_TS +DATA/itscmp/plugged/data3/amg_album_idx_ts02.dbf 3,003 1 0.6 1.0 2 0 0 0.0
Tablespace 表空间名
FileName 数据文件的路径
Reads: 该数据文件上累计发生过的物理读次数,不是块数
Av Reads/s: 该数据文件上平均每秒发生过的物理读次数,不是块数
Av Rd(ms): 该数据文件上平均每次物理读取的延迟,单位为ms
Av Blks/Rd: 该数据文件上平均每次读取涉及到的块数,OLTP环境该值接近 1
Writes : 该数据文件上累计发生过的物理写次数,不是块数
Av Writes/s: 该数据文件上平均每秒发生过的物理写次数,不是块数
buffer Waits: 该数据文件上发生buffer busy waits和read by other session的次数( 9i中buffer busy waits包含了read by other session)。
Av Buf Wt(ms): 该数据文件上发生buffer Waits的平均等待时间,单位为ms
若某个表空间上有较高的IO负载,则有必要分析一下 是否其所属的数据文件上的IO 较为均匀 还是存在倾斜, 是否需要结合存储特征来 将数据均衡分布到不同磁盘上的数据文件上,以优化 I/O
6 缓冲池统计 Buffer Pool Statistics
Buffer Pool Statistics Snaps: 70719-70723 -> Standard block size Pools D: default, K: keep, R: recycle -> Default Pools for other block sizes: 2k, 4k, 8k, 16k, 32k Free Writ Buffer Number of Pool Buffer Physical Physical Buff Comp Busy P Buffers Hit% Gets Reads Writes Wait Wait Waits --- ---------- ---- ------------ ------------ ----------- ------ ------ -------- 16k 15,720 N/A 0 0 0 0 0 0 D 2,259,159 98 2.005084E+09 42,753,650 560,460 0 1 8.51E+06
该环节的数据主要来源于WRH$_BUFFER_POOL_STATISTICS, 而WRH$_BUFFER_POOL_STATISTICS是定期汇总v$SYSSTAT中的数据
P pool池的名字 D: 默认的缓冲池 default buffer pool , K : Keep Pool , R: Recycle Pool ; 2k 4k 8k 16k 32k: 代表各种非标准块大小的缓冲池
Number of buffers: 实际的 缓冲块数目, 约等于 池的大小 / 池的块大小
Pool Hit % : 该缓冲池的命中率
Buffer Gets: 对该缓冲池的中块的访问次数 包括 consistent gets 和 db block gets
Physical Reads: 该缓冲池Buffer Cache引起了多少物理读, 其实是physical reads cache ,单位为 块数*次数
Physical Writes :该缓冲池中Buffer cache被写的物理写, 其实是physical writes from cache, 单位为 块数*次数
Free Buffer Waits: 等待空闲缓冲的次数, 可以看做该buffer pool 发生free buffer waits 等待的次数
Write Comp Wait: 等待DBWR写入脏buffer到磁盘的次数, 可以看做该buffer pool发生write complete waits等待的次数
Buffer Busy Waits: 该缓冲池发生buffer busy wait 等待的次数
7-1 Checkpoint Activity 检查点与 Instance Recovery Stats 实例恢复
Checkpoint Activity Snaps: 70719-70723 -> Total Physical Writes: 590,563 Other Autotune Thread MTTR Log Size Log Ckpt Settings Ckpt Ckpt Writes Writes Writes Writes Writes Writes ----------- ----------- ----------- ----------- ----------- ----------- 0 0 0 0 12,899 0 ------------------------------------------------------------- Instance Recovery Stats Snaps: 70719-70723 -> B: Begin Snapshot, E: End Snapshot Estd Targt Estd Log Ckpt Log Ckpt Opt RAC MTTR MTTR Recovery Actual Target Log Sz Timeout Interval Log Avail (s) (s) Estd IOs RedoBlks RedoBlks RedoBlks RedoBlks RedoBlks Sz(M) Time - ----- ----- -------- -------- -------- -------- -------- -------- ------ ----- B 0 6 12828 477505 1786971 5096034 1786971 N/A N/A 3 E 0 7 16990 586071 2314207 5096034 2314207 N/A N/A 3 -------------------------------------------------------------
该环节的数据来源于WRH$_INSTANCE_RECOVERY
MTTR Writes : 为了满足FAST_START_MTTR_TARGET 指定的MTTR值 而做出的物理写 WRITES_MTTR
Log Size Writes :由于最小的redo log file而做出的物理写 WRITES_LOGFILE_SIZE
Log Ckpt writes: 由于 LOG_CHECKPOINT_INTERVAL 和 LOG_CHECKPOINT_TIMEOUT 驱动的增量检查点而做出的物理写 WRITES_LOG_CHECKPOINT_SETTINGS
Other Settings Writes :由于其他设置(例如FAST_START_IO_TARGET)而引起的物理写, WRITES_OTHER_SETTINGS
Autotune Ckpt Writes : 由于自动调优检查点而引起的物理写, WRITES_AUTOTUNE
Thread Ckpt Writes :由于thread checkpoint而引起的物理写,WRITES_FULL_THREAD_CKPT
B 代表 开始点, E 代表结尾
Targt MTTR (s) : 目标MTTR (mean time to recover)意为有效恢复时间,单位为秒。 TARGET_MTTR 的计算基于 给定的参数FAST_START_MTTR_TARGET,而TARGET_MTTR作为内部使用。 实际在使用中 Target MTTR未必能和FAST_START_MTTR_TARGET一样。 如果FAST_START_MTTR_TARGET过小,那么TARGET_MTTR 将是系统条件所允许的最小估算值; 如果FAST_START_MTTR_TARGET过大,则TARGET_MTTR以保守算法计算以获得完成恢复的最长估算时间。
estimated_mttr (s): 当前基于 脏buffer和重做日志块的数量,而评估出的有效恢复时间 。 它的估算告诉用户 以当下系统的负载若发生实例crash,则需要多久时间来做crash recovery的前滚操作,之后才能打开数据库。
Recovery Estd IOs :实际是当前buffer cache中的脏块数量,一旦实例崩溃 这些脏块要被前滚
Actual RedoBlks : 当前实际需要恢复的redo重做块数量
Target RedoBlks :是 Log Sz RedoBlks 、Log Ckpt Timeout RedoBlks、 Log Ckpt Interval RedoBlks 三者的最小值
Log Sz RedoBlks : 代表 必须在log file switch日志切换之前完成的 checkpoint 中涉及到的redo block,也叫max log lag; 数据来源select LOGFILESZ from X$targetrba; select LOG_FILE_SIZE_REDO_BLKS from v$instance_recovery;
Log Ckpt Timeout RedoBlks : 为了满足LOG_CHECKPOINT_TIMEOUT 所需要处理的redo block数,lag for checkpoint timeout ; 数据来源select CT_LAG from x$targetrba;
Log Ckpt Interval RedoBlks :为了满足LOG_CHECKPOINT_INTERVAL 所需要处理的redo block数, lag for checkpoint interval; 数据来源select CI_LAG from x$targetrba;
Opt Log Sz(M) : 基于FAST_START_MTTR_TARGET 而估算出来的redo logfile 的大小,单位为MB 。 Oracle官方推荐创建的重做日志大小至少大于这个估算值
Estd RAC Avail Time :指评估的 RAC中节点失败后 集群从冻结到部分可用的时间, 这个指标仅在RAC中可用,单位为秒。 ESTD_CLUSTER_AVAILABLE_TIME
7-2 Buffer Pool Advisory 缓冲池建议
Buffer Pool Advisory DB/Inst: ITSCMP/itscmp2 Snap: 70723 -> Only rows with estimated physical reads >0 are displayed -> ordered by Block Size, Buffers For Estimate Est Phys Estimated Est Size for Size Buffers Read Phys Reads Est Phys %DBtime P Est (M) Factor (thousands) Factor (thousands) Read Time for Rds --- -------- ------ ------------ ------ -------------- ------------ ------- D 1,920 .1 227 4.9 1,110,565,597 1 1.0E+09 D 3,840 .2 454 3.6 832,483,886 1 7.4E+08 D 5,760 .3 680 2.8 634,092,578 1 5.6E+08 D 7,680 .4 907 2.2 500,313,589 1 4.3E+08 D 9,600 .5 1,134 1.8 410,179,557 1 3.5E+08 D 11,520 .6 1,361 1.5 348,214,283 1 2.9E+08 D 13,440 .7 1,588 1.3 304,658,441 1 2.5E+08 D 15,360 .8 1,814 1.2 273,119,808 1 2.2E+08 D 17,280 .9 2,041 1.1 249,352,943 1 2.0E+08 D 19,200 1.0 2,268 1.0 230,687,206 1 1.8E+08 D 19,456 1.0 2,298 1.0 228,664,269 1 1.8E+08 D 21,120 1.1 2,495 0.9 215,507,858 1 1.7E+08 D 23,040 1.2 2,722 0.9 202,816,787 1 1.6E+08 D 24,960 1.3 2,948 0.8 191,974,196 1 1.5E+08 D 26,880 1.4 3,175 0.8 182,542,765 1 1.4E+08 D 28,800 1.5 3,402 0.8 174,209,199 1 1.3E+08 D 30,720 1.6 3,629 0.7 166,751,631 1 1.2E+08 D 32,640 1.7 3,856 0.7 160,002,420 1 1.2E+08 D 34,560 1.8 4,082 0.7 153,827,351 1 1.1E+08 D 36,480 1.9 4,309 0.6 148,103,338 1 1.1E+08 D 38,400 2.0 4,536 0.6 142,699,866 1 1.0E+08
缓冲池的颗粒大小 可以参考 SELECT * FROM V$SGAINFO where name like(‘Granule%’);
P 指 缓冲池的名字 可能包括 有 D default buffer pool , K Keep Pool , R recycle Pool
Size For Est(M): 指以该尺寸的buffer pool作为评估的对象,一般是 目前current size的 10% ~ 200%,以便了解 buffer pool 增大 ~减小 对物理读的影响
Size Factor : 尺寸因子, 只 对应buffer pool 大小 对 当前设置的比例因子, 例如current_size是 100M , 则如果评估值是110M 那么 size Factor 就是 1.1
Buffers (thousands) :指这个buffer pool 尺寸下的buffer 数量, 要乘以1000才是实际值
Est Phys Read Factor :评估的物理读因子, 例如当前尺寸的buffer pool 会引起100个物理读, 则别的尺寸的buffer pool如果引起 120个物理读, 那么 对应尺寸的Est Phys Read Factor就是1.2
Estimated Phys Reads (thousands):评估的物理读数目, 要乘以 1000才是实际值, 显然不同尺寸的buffer pool对应不同的评估的物理读数目
Est Phys Read Time : 评估的物理读时间
Est %DBtime for Rds:评估的物理读占DB TIME的比率
我们 看buffer pool advisory 一般有2个目的:
- 在物理读较多的情况下,希望通过增加buffer pool 大小来缓解物理读等待,这是我们关注Size Factor > 1的buffer pool尺寸是否能共有效减少Est Phys Read Factor, 如果Est Phys Read Factor随着Size Factor 增大 而显著减少,那么说明增大buffer cache 是可以有效减少物理读的。
- 在内存紧张的情况下 ,希望从buffer pool中匀出部分内存来移作他用, 但是又不希望 buffer cache变小导致 物理读增多 性能下降, 则此时 观察Est Phys Read Factor 是否随着Size Factor 减小而 显著增大, 如果不是 则说明减少部分buffer cache 不会导致 物理读大幅增加,也就可以安心 减少 buffer cache
注意 Size Factor 和 Est Phys Read Factor之间不是简单的 线性关系,所以需要人为介入评估得失
7-3 PGA Aggr Summary
PGA Aggr Summary Snaps: 70719-70723 -> PGA cache hit % - percentage of W/A (WorkArea) data processed only in-memory PGA Cache Hit % W/A MB Processed Extra W/A MB Read/Written --------------- ------------------ -------------------------- 99.9 412,527 375
PGA Cache Hit % : 指 W/A WorkArea工作区的数据仅在内存中处理的比率, PGA缓存命中率
workarea是PGA中负责处理 排序、哈希连接和位图合并操作的区域; workarea 也叫做 SQL 作业区域
W/A MB processes: 指 在Workarea中处理过的数据的量,单位为MB
Extra W/A MB Read/Written : 指额外从磁盘上 读写的 工作区数据, 单位为 MB
7-4 PGA Aggr Target Stats
Warning: pga_aggregate_target was set too low for current workload, as this value was exceeded during this interval. Use the PGA Advisory view to help identify a different value for pga_aggregate_target. PGA Aggr Target Stats Snaps: 70719-70723 -> B: Begin Snap E: End Snap (rows dentified with B or E contain data which is absolute i.e. not diffed over the interval) -> Auto PGA Target - actual workarea memory target -> W/A PGA Used - amount of memory used for all Workareas (manual + auto) -> %PGA W/A Mem - percentage of PGA memory allocated to workareas -> %Auto W/A Mem - percentage of workarea memory controlled by Auto Mem Mgmt -> %Man W/A Mem - percentage of workarea memory under manual control %PGA %Auto %Man PGA Aggr Auto PGA PGA Mem W/A PGA W/A W/A W/A Global Mem Target(M) Target(M) Alloc(M) Used(M) Mem Mem Mem Bound(K) - ---------- ---------- ---------- ---------- ------ ------ ------ ---------- B 8,192 512 23,690.5 150.1 .6 100.0 .0 838,860 E 8,192 512 23,623.6 156.9 .7 100.0 .0 838,860 -------------------------------------------------------------
此环节的数据来源主要是 WRH$_PGASTAT
PGA Aggr Target(M) :本质上就是pga_aggregate_target , 当然在AMM(memory_target)环境下 这个值可能会自动变化
Auto PGA Target(M) : 在自动PGA 管理模式下 实际可用的工作区内存 “aggregate PGA auto target “, 因为PGA还有其他用途 ,不能全部作为workarea memory
PGA Mem Alloc(M) :目前已分配的PGA内存, alloc 不等于 inuse 即分配的内存不等于在使用的内存,理论上PGA会将确实不使用的内存返回给OS(PGA memory freed back to OS) ,但是存在PGA占用大量内存而不释放的场景
在上例中 pga_aggregate_target 仅为8192M ,而实际processes 在 2,615~ 8000之间,如果一个进程耗费5MB的PGA 也需要 10000M的PGA ,而实际这里 PGA Mem Alloc(M)是23,690 M ,这说明 存在PGA 的过载, 需要调整pga_aggregate_target
W/A PGA Used(M) :所有的工作区workarea(包括manual和 auto)使用的内存总和量, 单位为MB
%PGA W/A Mem: 分配给workarea的内存量占总的PGA的比例, (W/A PGA Used)/PGA Mem Alloc
%Auto W/A Mem : AUTO 自动工作区管理所控制的内存(workarea_size_policy=AUTO) 占总的workarea内存的比例
%Man W/A Mem : MANUAL 手动工作区管理所控制的内存(workarea_size_policy=MANUAL)占总的workarea内存的比例
Global Mem Bound(K) : 指 在自动PGA管理模式下一个工作区所能分配的最大内存(注意 一个SQL执行过程中可能有多个工作区workarea)。 Global Mem Bound(K)这个指标在实例运行过程中将被持续性的修正,以反应数据库当时工作区的负载情况。显然在有众多活跃工作区的系统负载下相应地Global Mem Bound将会下降。 但应当保持global bound值不要小于1 MB , 否则建议 调高pga_aggregate_target
7-5 PGA Aggr Target Histogram
PGA Aggr Target Histogram Snaps: 70719-70723 -> Optimal Executions are purely in-memory operations Low High Optimal Optimal Total Execs Optimal Execs 1-Pass Execs M-Pass Execs ------- ------- -------------- -------------- ------------ ------------ 2K 4K 262,086 262,086 0 0 64K 128K 497 497 0 0 128K 256K 862 862 0 0 256K 512K 368 368 0 0 512K 1024K 440,585 440,585 0 0 1M 2M 68,313 68,313 0 0 2M 4M 169 161 8 0 4M 8M 50 42 8 0 8M 16M 82 82 0 0 16M 32M 1 1 0 0 32M 64M 12 12 0 0 128M 256M 2 0 2 0 -------------------------------------------------------------
数据来源:WRH$_SQL_WORKAREA_HISTOGRAM
Low Optimal: 此行所包含工作区workarea最适合内存要求的下限
High Optimal: 此行所包含工作区workarea最适合内存要求的上限
Total Execs: 在 Low Optimal~High Optimal 范围工作区内完成的总执行数
Optimal execs: optimal 执行是指完全在PGA内存中完成的执行次数
1-pass Execs : 指操作过程中仅发生1次磁盘读取的执行次数
M-pass Execs: 指操作过程中发生了1次以上的磁盘读取, 频发磁盘读取的执行次数
7-6 PGA Memory Advisory
PGA Memory Advisory Snap: 70723 -> When using Auto Memory Mgmt, minimally choose a pga_aggregate_target value where Estd PGA Overalloc Count is 0 Estd Extra Estd P Estd PGA PGA Target Size W/A MB W/A MB Read/ Cache Overallo Estd Est (MB) Factr Processed Written to Disk Hit % Count Time ---------- ------- ---------------- ---------------- ------ -------- ------- 1,024 0.1 2,671,356,938.7 387,531,258.9 87.0 1.07E+07 7.9E+11 2,048 0.3 2,671,356,938.7 387,529,979.1 87.0 1.07E+07 7.9E+11 4,096 0.5 2,671,356,938.7 387,518,881.8 87.0 1.07E+07 7.9E+11 6,144 0.8 2,671,356,938.7 387,420,749.5 87.0 1.07E+07 7.9E+11 8,192 1.0 2,671,356,938.7 23,056,196.5 99.0 1.07E+07 6.9E+11 9,830 1.2 2,671,356,938.7 22,755,192.6 99.0 6.81E+06 6.9E+11 11,469 1.4 2,671,356,938.7 20,609,438.5 99.0 4.15E+06 6.9E+11 13,107 1.6 2,671,356,938.7 19,021,139.1 99.0 581,362 6.9E+11 14,746 1.8 2,671,356,938.7 18,601,191.0 99.0 543,531 6.9E+11 16,384 2.0 2,671,356,938.7 18,561,361.1 99.0 509,687 6.9E+11 24,576 3.0 2,671,356,938.7 18,527,422.3 99.0 232,817 6.9E+11 32,768 4.0 2,671,356,938.7 18,511,872.6 99.0 120,180 6.9E+11 49,152 6.0 2,671,356,938.7 18,500,815.3 99.0 8,021 6.9E+11 65,536 8.0 2,671,356,938.7 18,498,733.0 99.0 0 6.9E+11
PGA Target Est (MB) 用以评估的 PGA_AGGREGATE _TARGET值
Size Factr , 当前用以评估的PGA_AGGREGATE _TARGET 和 当前实际设置的PGA_AGGREGATE _TARGET 之间的 比例因子 PGA Target Est / PGA_AGGREGATE_TARGE
W/A MB Processed :workarea中要处理的数据量, 单位为MB
Estd Extra W/A MB Read/ Written to Disk : 以 one-pass 、M-Pass方式处理的数据量预估值, 单位为MB
Estd P Cache Hit % : 预估的PGA缓存命中率
Estd PGA Overalloc Count: 预估的PGA过载量, 如上文所述PGA_AGGREGATE _TARGET仅是一个目标值,无法真正限制PGA内存的使用,当出现 PGA内存硬性需求时会产生PGA overallocate 过载(When using Auto Memory Mgmt, minimally choose a pga_aggregate_target value where Estd PGA Overalloc Count is 0)
7-7 Shared Pool Advisory
Shared Pool Advisory Snap: 70723 -> SP: Shared Pool Est LC: Estimated Library Cache Factr: Factor -> Note there is often a 1:Many correlation between a single logical object in the Library Cache, and the physical number of memory objects associated with it. Therefore comparing the number of Lib Cache objects (e.g. in v$librarycache), with the number of Lib Cache Memory Objects is invalid. Est LC Est LC Est LC Est LC Shared SP Est LC Time Time Load Load Est LC Pool Size Size Est LC Saved Saved Time Time Mem Obj Size(M) Factr (M) Mem Obj (s) Factr (s) Factr Hits (K) -------- ----- -------- ------------ -------- ------ ------- ------ ------------ 304 .8 56 3,987 7,728 1.0 61 1.4 332 352 .9 101 6,243 7,745 1.0 44 1.0 334 400 1.0 114 7,777 7,745 1.0 44 1.0 334 448 1.1 114 7,777 7,745 1.0 44 1.0 334 496 1.2 114 7,777 7,745 1.0 44 1.0 334 544 1.4 114 7,777 7,745 1.0 44 1.0 334 592 1.5 114 7,777 7,745 1.0 44 1.0 334 640 1.6 114 7,777 7,745 1.0 44 1.0 334 688 1.7 114 7,777 7,745 1.0 44 1.0 334 736 1.8 114 7,777 7,745 1.0 44 1.0 334 784 2.0 114 7,777 7,745 1.0 44 1.0 334 832 2.1 114 7,777 7,745 1.0 44 1.0 334 -------------------------------------------------------------
Shared Pool Size(M) : 用以评估的shared pool共享池大小,在AMM /ASMM环境下 shared_pool 大小都可能浮动
SP Size Factr :共享池大小的比例因子, (Shared Pool Size for Estim / SHARED_POOL_SIZE)
Estd LC Size(M) : 评估的 library cache 大小 ,单位为MB , 因为是shared pool中包含 library cache 当然还有其他例如row cache
Est LC Mem Obj 指评估的指定大小的共享池内的library cache memory object的数量 ESTD_LC_MEMORY_OBJECTS
Est LC Time Saved(s): 指在 指定的共享池大小情况下可找到需要的library cache memory objects,从而节约的解析时间 。 这些节约的解析时间也是 花费在共享池内重复加载需要的对象(reload),这些对象可能因为共享池没有足够的free memory而被aged out. ESTD_LC_TIME_SAVED
Est LC Time Saved Factr : Est LC Time Saved(s)的比例因子,( Est LC Time Saved(s)/ Current LC Time Saved(s) ) ESTD_LC_TIME_SAVED_FACTOR
Est LC Load Time (s): 在指定的共享池大小情况下解析的耗时
Est LC Load Time Factr:Est LC Load Time (s)的比例因子, (Est LC Load Time (s)/ Current LC Load Time (s)) ESTD_LC_LOAD_TIME_FACTOR
Est LC Mem Obj Hits (K) : 在指定的共享池大小情况下需要的library cache memory object正好在共享池中被找到的次数 ESTD_LC_MEMORY_OBJECT_HITS;
对于想缩小 shared_pool_size 共享池大小的需求,可以关注Est LC Mem Obj Hits (K) ,如上例中共享池为352M时Est LC Mem Obj Hits (K) 就为334且之后不动,则可以考虑缩小shared_pool_size到该值,但要注意每个版本/平台上对共享池的最低需求,包括RAC中gcs resource 、gcs shadow等资源均驻留在shared pool中,增大db_cache_size时要对应关注。
7-8 SGA Target Advisory
SGA Target Advisory Snap: 70723 SGA Target SGA Size Est DB Est Physical Size (M) Factor Time (s) Reads ---------- ---------- ------------ ---------------- 3,752 0.1 1.697191E+09 1.4577142918E+12 7,504 0.3 1.222939E+09 832,293,601,354 11,256 0.4 1.000162E+09 538,390,923,784 15,008 0.5 895,087,191 399,888,743,900 18,760 0.6 840,062,594 327,287,716,803 22,512 0.8 806,389,685 282,881,041,331 26,264 0.9 782,971,706 251,988,446,808 30,016 1.0 765,293,424 228,664,652,276 33,768 1.1 751,135,535 210,005,616,650 37,520 1.3 739,350,016 194,387,820,900 41,272 1.4 733,533,785 187,299,216,679 45,024 1.5 732,921,550 187,299,216,679 48,776 1.6 732,691,962 187,299,216,679 52,528 1.8 732,538,908 187,299,216,679 56,280 1.9 732,538,917 187,299,216,679 60,032 2.0 732,462,391 187,299,458,716 -------------------------------------------------------------
该环节数据来源于WRH$_SGA_TARGET_ADVICE
SGA target Size : 用以评估的sga target大小 (sga_target)
SGA Size Factor: SGA Size的比例因子, (est SGA target Size / Current SGA target Size )
Est DB Time (s): 评估对应于该指定sga target size会产生多少量的DB TIME,单位为秒
Est Physical Reads:评估对应该指定的sga target size 会产生多少的物理读
7-9 Streams Pool Advisory
Streams Pool Advisory DB/Inst: ITSCMP/itscmp2 Snap: 70723 Size for Size Est Spill Est Spill Est Unspill Est Unspill Est (MB) Factor Count Time (s) Count Time (s) ---------- --------- ----------- ----------- ----------- ----------- 64 0.5 0 0 0 0 128 1.0 0 0 0 0 192 1.5 0 0 0 0 256 2.0 0 0 0 0 320 2.5 0 0 0 0 384 3.0 0 0 0 0 448 3.5 0 0 0 0 512 4.0 0 0 0 0 576 4.5 0 0 0 0 640 5.0 0 0 0 0 704 5.5 0 0 0 0 768 6.0 0 0 0 0 832 6.5 0 0 0 0 896 7.0 0 0 0 0 960 7.5 0 0 0 0 1,024 8.0 0 0 0 0 1,088 8.5 0 0 0 0 1,152 9.0 0 0 0 0 1,216 9.5 0 0 0 0 1,280 10.0 0 0 0 0
该环节只有当使用了Streams 流复制时才会有必要数据, 数据来源 WRH$_STREAMS_POOL_ADVICE
Size for Est (MB) : 用以评估的 streams pool大小
Size Factor :streams pool大小的比例因子
Est Spill Count :评估出的 当使用该大小的流池时 message溢出到磁盘的数量 ESTD_SPILL_COUNT
Est Spill Time (s): 评估出的 当使用该大小的流池时 message溢出到磁盘的耗时,单位为秒 ESTD_SPILL_TIME
Est Unspill Count:评估的 当使用该大小的流池时 message unspill 即从磁盘上读取的数量 ESTD_UNSPILL_COUNT
Est Unspill Time (s) : 评估的 当使用该大小的流池时 message unspill 即从磁盘上读取的耗时,单位为秒 ESTD_UNSPILL_TIME
7-10 Java Pool Advisory
java pool的相关指标与shared pool相似,不再鏖述
8 Wait Statistics
8-1 Buffer Wait Statistics
Buffer Wait Statistics Snaps: 70719-70723 -> ordered by wait time desc, waits desc Class Waits Total Wait Time (s) Avg Time (ms) ------------------ ----------- ------------------- -------------- data block 8,442,041 407,259 48 undo header 16,212 1,711 106 undo block 21,023 557 26 1st level bmb 1,038 266 256 2nd level bmb 540 185 342 bitmap block 90 25 276 segment header 197 13 66 file header block 132 6 43 bitmap index block 18 0 1 extent map 2 0 0
数据来源 : WRH$_WAITSTAT
该环节是对 缓冲池中各类型(class) 块 等待的汇总信息, wait的原因一般是 buffer busy waits 和 read by other session
class 数据块的class, 一个oracle数据块即有class 属性 还有type 属性,数据块中记录type属性(KCBH), 而在buffer header里存有class属性(X$BH.class)
Waits: 该类型数据块的等待次数
Total Wait Time (s) : 该类型数据块的合计等待时间 单位为秒
Avg Time (ms) : 该类型数据块 平均每次等待的耗时, 单位 ms
如果用户正使用 undo_management=AUTO 的SMU 则一般不会因为rollback segment过少而引起undo header block类块的等待
对于INSERT 而引起的 buffer争用等待:
1、 对于手动segment 管理MSSM 考虑增加Freelists、Freelist Groups
2、 使用ASSM ,当然ASSM本身没什么参数可调
对于INSERT ON INDEX 引起的争用:
- 使用反向索引key
- 使用HASH分区和本地索引
- 可能的情况下 减少index的density
8-2 Enqueue Activity
enqueue 队列锁等待
Enqueue Activity Snaps: 70719-70723 -> only enqueues with waits are shown -> Enqueue stats gathered prior to 10g should not be compared with 10g data -> ordered by Wait Time desc, Waits desc Enqueue Type (Request Reason) ------------------------------------------------------------------------------ Requests Succ Gets Failed Gets Waits Wt Time (s) Av Wt Time(ms) ------------ ------------ ----------- ----------- ------------ -------------- TX-Transaction (index contention) 201,270 201,326 0 193,948 97,517 502.80 TM-DML 702,731 702,681 4 1,081 46,671 43,174.08 SQ-Sequence Cache 28,643 28,632 0 17,418 35,606 2,044.19 HW-Segment High Water Mark 9,210 8,845 376 1,216 12,505 10,283.85 TX-Transaction (row lock contention) 9,288 9,280 0 9,232 10,486 1,135.80 CF-Controlfile Transaction 15,851 14,094 1,756 2,798 4,565 1,631.64 TX-Transaction (allocate ITL entry) 471 369 102 360 169 469.28
Enqueue Type (Request Reason) enqueue 队列的类型,大家在研究 enqueue 问题前 至少搞清楚enqueue type 和enqueue mode , enqueue type是队列锁所要保护的资源 如 TM 表锁 CF 控制文件锁, enqueue mode 是持有队列锁的模式 (SS、SX 、S、SSX、X)
Requests : 申请对应的enqueue type资源或者队列转换(enqueue conversion 例如 S 转 SSX ) 的次数
Succ Gets :对应的enqueue被成功 申请或转换的次数
Failed Gets :对应的enqueue的申请 或者转换失败的次数
Waits :由对应的enqueue的申请或者转换而造成等待的次数
Wt Time (s) : 由对应的enqueue的申请或者转换而造成等待的等待时间
Av Wt Time(ms) :由对应的enqueue的申请或者转换而造成等待的平均等待时间 , Wt Time (s) / Waits ,单位为ms
主要的enqueue 等待事件:
enq: TX – row lock/index contention、allocate ITL等待事件
Oracle队列锁enq:TS,Temporary Segment (also TableSpace)
9-1 Undo Segment Summary
Undo Segment Summary Snaps: 70719-70723 -> Min/Max TR (mins) - Min and Max Tuned Retention (minutes) -> STO - Snapshot Too Old count, OOS - Out of Space count -> Undo segment block stats: -> uS - unexpired Stolen, uR - unexpired Released, uU - unexpired reUsed -> eS - expired Stolen, eR - expired Released, eU - expired reUsed Undo Num Undo Number of Max Qry Max Tx Min/Max STO/ uS/uR/uU/ TS# Blocks (K) Transactions Len (s) Concurcy TR (mins) OOS eS/eR/eU ---- ---------- --------------- -------- -------- --------- ----- -------------- 4 85.0 200,127 55,448 317 1040.2/10 0/0 0/0/0/0/0/0 ------------------------------------------------------------- Undo Segment Stats Snaps: 70719-70723 -> Most recent 35 Undostat rows, ordered by Time desc Num Undo Number of Max Qry Max Tx Tun Ret STO/ uS/uR/uU/ End Time Blocks Transactions Len (s) Concy (mins) OOS eS/eR/eU ------------ ----------- ------------ ------- ------- ------- ----- ------------ 29-Aug 05:52 11,700 35,098 55,448 234 1,070 0/0 0/0/0/0/0/0 29-Aug 05:42 12,203 24,677 54,844 284 1,065 0/0 0/0/0/0/0/0 29-Aug 05:32 14,132 37,826 54,241 237 1,060 0/0 0/0/0/0/0/0 29-Aug 05:22 14,379 32,315 53,637 317 1,050 0/0 0/0/0/0/0/0 29-Aug 05:12 15,693 34,157 53,033 299 1,045 0/0 0/0/0/0/0/0 29-Aug 05:02 16,878 36,054 52,428 250 1,040 0/0 0/0/0/0/0/0
数据来源: WRH$_UNDOSTAT , undo相关的使用信息每10分钟刷新到v$undostat中
Undo Extent有三种状态 active 、unexpired 、expired
active => extent中 包括了活动的事务 ,active的undo extent 一般不允许被其他事务重用覆盖
unexpired => extent中没有活动的事务,但相关undo 记录从inactive到目前还未经过undo retention(注意 auto undo retention的问题 因为这个特性 可能在观察dba_undo_extents时看到大部分block都是unexpired,这是正常的) 指定的时间,所以为unexpired。 对于没有guarantee retention的undo tablespace而言,unexpired extent可能被 steal 为其他事物重用
expired => extent中没有活动事务,且超过了undo retention的时间
Undo TS# 在使用的这个undo 表空间的表空间号, 一个实例 同一时间只能用1个undo tablespace , RAC不同节点可以用不同的undo tablespace
Num Undo Blocks (K) 指被消费的 undo 数据块的数量, (K)代表要乘以1000才是实际值; 可以用该指标来评估系统对undo block的消费量, 以便基于实际负载情况来评估UNDO表空间的大小
Number of Transactions 指该段时间内该undo表空间上执行过的事务transaction总量
Max Qry Len (s) 该时段内 持续最久的查询 时间, 单位为秒
Max Tx Concy 该时段内 最大的事务并发量
Min/Max TR (mins) 最小和最大的tuned undo retention ,单位为分钟; tuned undo retention 是自动undo调优特性,见undo自动调优介绍。
STO/ OOS STO 指 ORA-01555 Snapshot Too Old错误出现的次数; OOS – 指Out of Space count 错误出现的次数
uS – unexpired Stolen 尝试从未过期的undo extent中偷取undo space的次数
uR – unexpired Released 从未过期的undo extent中释放的块数目
uU – unexpired reUsed 未过期的undo extent中的block被其他事务重用的 块数目
eS – expired Stolen 尝试从过期的undo extent中偷取undo space的次数
eR – expired Released 从过期的undo extent中释放的块数目
eU – expired reUsed 过期的undo extent中的block被其他事务重用的 块数目
UNXPSTEALCNT |
NUMBER |
Number of attempts to obtain undo space by stealing unexpired extents from other transactions |
UNXPBLKRELCNT |
NUMBER |
Number of unexpired blocks removed from certain undo segments so they can be used by other transactions |
UNXPBLKREUCNT |
NUMBER |
Number of unexpired undo blocks reused by transactions |
EXPSTEALCNT |
NUMBER |
Number of attempts to steal expired undo blocks from other undo segments |
EXPBLKRELCNT |
NUMBER |
Number of expired undo blocks stolen from other undo segments |
EXPBLKREUCNT |
NUMBER |
Number of expired undo blocks reused within the same undo segments |
SSOLDERRCNT |
NUMBER |
Identifies the number of times the error ORA-01555 occurred. You can use this statistic to decide whether or not the UNDO_RETENTION initialization parameter is set properly given the size of the undo tablespace. Increasing the value of UNDO_RETENTION can reduce the occurrence of this error. |
10-1 Latch Activity
Latch Activity Snaps: 70719-70723 -> "Get Requests", "Pct Get Miss" and "Avg Slps/Miss" are statistics for willing-to-wait latch get requests -> "NoWait Requests", "Pct NoWait Miss" are for no-wait latch get requests -> "Pct Misses" for both should be very close to 0.0 Pct Avg Wait Pct Get Get Slps Time NoWait NoWait Latch Name Requests Miss /Miss (s) Requests Miss ------------------------ -------------- ------ ------ ------ ------------ ------ AQ deq hash table latch 4 0.0 0 0 N/A ASM Keyed state latch 9,048 0.1 0.2 0 0 N/A ASM allocation 15,017 0.2 0.8 1 0 N/A ASM db client latch 72,745 0.0 0 0 N/A ASM map headers 5,860 0.6 0.6 1 0 N/A ASM map load waiting lis 1,462 0.0 0 0 N/A ASM map operation freeli 63,539 0.1 0.4 1 0 N/A ASM map operation hash t 76,484,447 0.1 1.0 66 0 N/A
latch name Latch闩的名字
Get Requests latch被以willing-to-wait模式申请并获得的次数
Pct Get Miss miss是指latch被以willing-to-wait 模式申请但是申请者必须等待的次数, Pct Get Miss = Miss/Get Requests ; miss可以从后面的Latch Sleep Breakdown 获得
Avg Slps /Miss Sleep 是指latch被以willing-to-wait模式申请最终导致session需要sleep以等待该latch的次数 ; Avg Slps /Miss = Sleeps/ Misses ; Sleeps可以从后面的Latch Sleep Breakdown 获得
Wait Time (s) 指花费在等待latch上的时间,单位为秒
NoWait Requests 指latch被以no-wait模式来申请的次数
Pct NoWait Miss 以no-wait模式来申请latch但直接失败的次数
对于高并发的latch例如cache buffers chains,其Pct Misses应当十分接近于0
一般的调优原则:
如果latch : cache buffers chains是 Top 5 事件,则需要考虑优化SQL减少 全表扫描 并减少Top buffer gets SQL语句的逻辑读
如果latch : redo copy 、redo allocation 等待较多,则可以考虑增大LOG_BUFFER
如果latch:library cache 发生较多,则考虑增大shared_pool_size
10-2 Latch Sleep Breakdown
Latch Sleep Breakdown DB/Inst: ITSCMP/itscmp2 Snaps: 70719-70723 -> ordered by misses desc Get Spin Latch Name Requests Misses Sleeps Gets -------------------------- --------------- ------------ ----------- ----------- cache buffers chains 3,365,097,866 12,831,875 130,058 12,683,450 row cache objects 69,050,058 349,839 1,320 348,649 session idle bit 389,437,460 268,285 2,768 265,752 enqueue hash chains 8,698,453 239,880 22,476 219,950 ges resource hash list 8,388,730 158,894 70,728 91,104 gc element 100,383,385 135,759 6,285 129,742 gcs remastering latch 12,213,169 72,373 1 72,371 enqueues 4,662,545 46,374 259 46,155 ASM map operation hash tab 76,484,447 46,231 45,210 1,952 Lsod array latch 72,598 24,224 24,577 1,519
latch name Latch闩的名字
Get Requests latch被以willing-to-wait模式申请并获得的次数
misses 是指latch被以willing-to-wait 模式申请但是申请者必须等待的次数
9i以后miss之后一般有2种情况 spin gets了 或者sleep一睡不醒直到 被post,具体见全面解析9i以后Oracle Latch闩锁原理;
8i以前的latch算法可以参考:Oracle Latch:一段描绘Latch运作的伪代码
所以一般来说9i以后的 misses= Sleeps+ Spin Gets ,虽然不是绝对如此
Sleeps 是指latch被以willing-to-wait模式申请最终导致session需要sleep以等待该latch的次数
Spin Gets 以willing-to-wait模式去申请latch,在miss之后以spin方式获得了latch的次数
10-3 Latch Miss Sources
Latch Miss Sources Snaps: 70719-70723 -> only latches with sleeps are shown -> ordered by name, sleeps desc NoWait Waiter Latch Name Where Misses Sleeps Sleeps ------------------------ -------------------------- ------- ---------- -------- ASM Keyed state latch kfksolGet 0 1 1 ASM allocation kfgpnSetDisks2 0 17 0 ASM allocation kfgpnClearDisks 0 5 0 ASM allocation kfgscCreate 0 4 0 ASM allocation kfgrpGetByName 0 1 26 ASM map headers kffmUnidentify_3 0 7 8 ASM map headers kffmAllocate 0 6 0 ASM map headers kffmIdentify 0 6 11 ASM map headers kffmFree 0 1 0 ASM map operation freeli kffmTranslate2 0 15 8 ASM map operation hash t kffmUnidentify 0 44,677 36,784 ASM map operation hash t kffmTranslate 0 220 3,517
数据来源为DBA_HIST_LATCH_MISSES_SUMMARY
latch name Latch闩的名字
where : 指哪些代码路径内核函数持有过这些该latch ,而不是哪些代码路径要申请这些latch; 例如kcbgtcr函数的作用是Get a block for Consistent read,其持有latch :cache buffers chain是很正常的事情
NoWait Misses: 以no-wait模式来申请latch但直接失败的次数
Sleeps: 指latch被以willing-to-wait模式申请最终导致session需要sleep以等待该latch的次数 time of sleeps resulted in making the latch request
Waiter Sleeps:等待者休眠的次数 times of sleeps that waiters did for each where; Sleep 是阻塞者等待的次数 , Waiter Sleeps是被阻塞者等待的次数
10-4 Mutex Sleep Summary
Mutex Sleep Summary Snaps: 70719-70723 -> ordered by number of sleeps desc Wait Mutex Type Location Sleeps Time (ms) --------------------- -------------------------------- ------------ ------------ Cursor Pin kksfbc [KKSCHLFSP2] 4,364 14,520 Cursor Pin kkslce [KKSCHLPIN2] 2,396 2,498 Library Cache kglpndl1 95 903 475 Library Cache kglpin1 4 800 458 Library Cache kglpnal2 91 799 259 Library Cache kglget1 1 553 1,697 Library Cache kglpnal1 90 489 88 Library Cache kgllkdl1 85 481 1,528 Cursor Pin kksLockDelete [KKSCHLPIN6] 410 666 Cursor Stat kkocsStoreBindAwareStats [KKSSTA 346 497 Library Cache kglhdgn2 106 167 348 Library Cache kglhdgh1 64 26 84 Library Cache kgldtin1 42 19 55 Cursor Pin kksfbc [KKSCHLPIN1] 13 34 Library Cache kglhdgn1 62 11 13 Library Cache kgllkal1 80 9 12 Library Cache kgllkc1 57 6 0 Cursor Pin kksSetBindType [KKSCHLPIN3] 5 5 Library Cache kglGetHandleReference 124 4 20 Library Cache kglUpgradeLock 119 4 0 Library Cache kglget2 2 3 0 Library Cache kglati1 45 1 0 Library Cache kglini1 32 1 0 Library Cache kglobld1 75 1 0 Library Cache kglobpn1 71 1 0
Mutex是10.2.0.2以后引入的新的内存锁机制,具体对Mutex的描述见 《深入理解Oracle中的Mutex》:http://www.askmaclean.com/archives/understanding-oracle-mutex.html
Mutex Type
Mutex的类型其实就是 mutex对应的客户的名字, 在版本10.2中基本只有KKS使用Mutex,所以仅有3种:
- Cursor Stat (kgx_kks1)
- Cursor Parent (kgx_kks2)
- Cursor Pin (kgx_kks3)
11g中增加了Library Cache
Location 发起对该Mutex申请的代码路径code location,而不是还持有该Mutex的代码路径或曰内核函数
10.2中最常见的下面的几个函数
kkspsc0 -负责解析游标 – 检测我们正在解析的游标是否有对象的parent cursor heap 0存在
kksfbc – 负责找到合适的子游标 或者创建一个新的子游标
kksFindCursorstat
Sleeps:
Mutex的Get和Sleep
当一个Mutex被申请时, 一般称为一个get request。 若初始的申请未能得到授权, 则该进程会因为此次申请而进入到255次SPIN中(_mutex_spin_count Mutex spin count),每次SPIN循环迭代过程中该进程都会去看看Mutex被释放了吗。
若该Mutex在SPIN之后仍未被释放,则该进程针对申请的mutex进入对应的mutex wait等待事件中。 实际进程的等待事件和等待方式由mutex的类型锁决定,例如 Cursor pin、Cursor Parent。 举例来说,这种等待可能是阻塞等待,也可以是sleep。
但是请注意在V$MUTEX_SLEEP_*视图上的sleep列意味着等待的次数。相关代码函数在开始进入等待时自加这个sleep字段。
等待计时从进程进入等待前开始计算等待时间, 当一个进程结束其等待,则等待的时间加入都总和total中。 该进程再次尝试申请之前的Mutex,若该Mutex仍不可用,则它再次进入spin/wait的循环。
V$MUTEX_SLEEP_HISTORY视图的GETS列仅在成功申请到一个Mutex时才增加。
Wait Time (ms) 类似于latch,spin time 不算做mutex的消耗时间,它只包含等待消耗的时间。
=====================================================================
11 segment statistics 段级统计
11-1 Segments by Logical Reads
Segments by Logical Reads DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> Total Logical Reads: 2,021,476,421 -> Captured Segments account for 83.7% of Total Tablespace Subobject Obj. Logical Owner Name Object Name Name Type Reads %Total ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW INDEX_TS MZ_PRODUCT_ATTRIBUTE INDEX 372,849,920 18.44 CONTENT_OW INDEX_TS MZ_PRODUCT__LS_PK INDEX 329,829,632 16.32 CONTENT_OW DATA_TS MZ_PRODUCT_ATTRIBUTE TABLE 218,419,008 10.80 CONTENT_OW PLAYLIST_A MZ_PLAYLIST_ARTIST TABLE 182,426,240 9.02 CONTENT_OW DATA_TS MZ_PRODUCT TABLE 108,597,376 5.37
owner : 数据段的所有者
Tablespace Name: 数据段所在表空间名
Object Name : 对象名
Subobject Name:子对象名,例如一个分区表的某个分区
obj Type: 对象类型 一般为TABLE /INDEX 或者分区或子分区
Logical Reads :该数据段上发生过的逻辑读 , 单位为 块数*次数
%Total : 占总的逻辑读的百分比 , (当前对象上发生过的逻辑读/ Total DB 逻辑读)
11-2 Segments by Physical Reads
Segments by Physical Reads DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> Total Physical Reads: 56,839,035 -> Captured Segments account for 51.9% of Total Tablespace Subobject Obj. Physical Owner Name Object Name Name Type Reads %Total ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW SONG_TS MZ_SONG TABLE 7,311,928 12.86 CONTENT_OW DATA_TS MZ_CS_WORK_PENDING_R TABLE 4,896,554 8.61 CONTENT_OW DATA_TS MZ_CONTENT_PROVIDER_ TABLE 3,099,387 5.45 CONTENT_OW DATA_TS MZ_PRODUCT_ATTRIBUTE TABLE 1,529,971 2.69 CONTENT_OW DATA_TS MZ_PUBLICATION TABLE 1,391,735 2.45
Physical Reads: 该数据段上发生过的物理读 , 单位为 块数*次数
%Total : 占总的物理读的百分比 , (当前对象上发生过的逻辑读/ Total DB 逻辑读)
11-3 Segments by Physical Read Requests
Segments by Physical Read Requests DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> Total Physical Read Requests: 33,936,360 -> Captured Segments account for 45.5% of Total Tablespace Subobject Obj. Phys Read Owner Name Object Name Name Type Requests %Total ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW DATA_TS MZ_CONTENT_PROVIDER_ TABLE 3,099,346 9.13 CONTENT_OW DATA_TS MZ_PRODUCT_ATTRIBUTE TABLE 1,529,950 4.51 CONTENT_OW DATA_TS MZ_PRODUCT TABLE 1,306,756 3.85 CONTENT_OW DATA_TS MZ_AUDIO_FILE TABLE 910,537 2.68 CONTENT_OW INDEX_TS MZ_PRODUCT_ATTRIBUTE INDEX 820,459 2.42
Phys Read Requests : 物理读的申请次数
%Total : (该段上发生的物理读的申请次数/ physical read IO requests)
11-4 Segments by UnOptimized Reads
Segments by UnOptimized Reads DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> Total UnOptimized Read Requests: 811,466 -> Captured Segments account for 58.5% of Total Tablespace Subobject Obj. UnOptimized Owner Name Object Name Name Type Reads %Total ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW DATA_TS MZ_CONTENT_PROVIDER_ TABLE 103,580 12.76 CONTENT_OW SONG_TS MZ_SONG TABLE 56,946 7.02 CONTENT_OW DATA_TS MZ_IMAGE TABLE 47,017 5.79 CONTENT_OW DATA_TS MZ_PRODUCT_ATTRIBUTE TABLE 40,950 5.05 CONTENT_OW DATA_TS MZ_PRODUCT TABLE 30,406 3.75
UnOptimized Reads UnOptimized Read Reqs = Physical Read Reqts – Optimized Read Reqs
Optimized Read Requests是指 哪些满足Exadata Smart Flash Cache ( or the Smart Flash Cache in OracleExadata V2 (Note that despite same name, concept and use of
‘Smart Flash Cache’ in Exadata V2 is different from ‘Smart Flash Cache’ in Database Smart Flash Cache)).的物理读 次数 。 满足从smart flash cache走的读取申请呗认为是optimized ,因为这些读取要比普通从磁盘走快得多。
此外通过smart scan 读取storage index的情况也被认为是’optimized read requests’ ,源于可以避免读取不相关的数据。
当用户不在使用Exadata时,则UnOptimized Read Reqs总是等于 Physical Read Reqts
%Total : (该段上发生的物理读的UnOptimized Read Reqs / ( physical read IO requests – physical read requests optimized ))
11-5 Segments by Optimized Reads
Segments by Optimized Reads DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> Total Optimized Read Requests: 33,124,894 -> Captured Segments account for 45.2% of Total Tablespace Subobject Obj. Optimized Owner Name Object Name Name Type Reads %Total ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW DATA_TS MZ_CONTENT_PROVIDER_ TABLE 2,995,766 9.04 CONTENT_OW DATA_TS MZ_PRODUCT_ATTRIBUTE TABLE 1,489,000 4.50 CONTENT_OW DATA_TS MZ_PRODUCT TABLE 1,276,350 3.85 CONTENT_OW DATA_TS MZ_AUDIO_FILE TABLE 890,775 2.69 CONTENT_OW INDEX_TS MZ_AM_REQUEST_IX3 INDEX 816,067 2.46
关于optimizerd read 上面已经解释过了,这里的单位是 request 次数
%Total : (该段上发生的物理读的 Optimized Read Reqs/ physical read requests optimized )
11-6 Segments by Direct Physical Reads
Segments by Direct Physical Reads DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> Total Direct Physical Reads: 14,118,552 -> Captured Segments account for 94.2% of Total Tablespace Subobject Obj. Direct Owner Name Object Name Name Type Reads %Total ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW SONG_TS MZ_SONG TABLE 7,084,416 50.18 CONTENT_OW DATA_TS MZ_CS_WORK_PENDING_R TABLE 4,839,984 34.28 CONTENT_OW DATA_TS MZ_PUBLICATION TABLE 1,361,133 9.64 CONTENT_OW DATA_TS SYS_LOB0000203660C00 LOB 5,904 .04 CONTENT_OW DATA_TS SYS_LOB0000203733C00 LOB 1,656 .01
Direct reads 直接路径物理读,单位为 块数*次数
%Total (该段上发生的direct path reads /Total physical reads direct )
11-7 Segments by Physical Writes
Segments by Physical Writes DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> Total Physical Writes: 590,563 -> Captured Segments account for 38.3% of Total Tablespace Subobject Obj. Physical Owner Name Object Name Name Type Writes %Total ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW DATA_TS MZ_CS_WORK_PENDING_R TABLE 23,595 4.00 CONTENT_OW DATA_TS MZ_PODCAST TABLE 19,834 3.36 CONTENT_OW INDEX_TS MZ_IMAGE_IX2 INDEX 16,345 2.77 SYS SYSAUX WRH$_ACTIVE_SESSION_ 1367_70520 TABLE 14,173 2.40 CONTENT_OW INDEX_TS MZ_AM_REQUEST_IX3 INDEX 9,645 1.63
Physical Writes ,物理写 单位为 块数*次数
Total % (该段上发生的物理写 /Total physical writes )
11-9 Segments by Physical Write Requests
Segments by Physical Write Requests DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> Total Physical Write Requestss: 436,789 -> Captured Segments account for 43.1% of Total Tablespace Subobject Obj. Phys Write Owner Name Object Name Name Type Requests %Total ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW DATA_TS MZ_CS_WORK_PENDING_R TABLE 22,581 5.17 CONTENT_OW DATA_TS MZ_PODCAST TABLE 19,797 4.53 CONTENT_OW INDEX_TS MZ_IMAGE_IX2 INDEX 14,529 3.33 CONTENT_OW INDEX_TS MZ_AM_REQUEST_IX3 INDEX 9,434 2.16 CONTENT_OW DATA_TS MZ_AM_REQUEST TABLE 8,618 1.97
Phys Write Requests 物理写的请求次数 ,单位为次数
%Total (该段上发生的物理写请求次数 /physical write IO requests )
11-10 Segments by Direct Physical Writes
Segments by Direct Physical Writes DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> Total Direct Physical Writes: 29,660 -> Captured Segments account for 18.3% of Total Tablespace Subobject Obj. Direct Owner Name Object Name Name Type Writes %Total ---------- ---------- -------------------- ---------- ----- ------------ ------- SYS SYSAUX WRH$_ACTIVE_SESSION_ 1367_70520 TABLE 4,601 15.51 CONTENT_OW DATA_TS SYS_LOB0000203733C00 LOB 620 2.09 CONTENT_OW DATA_TS SYS_LOB0000203660C00 LOB 134 .45 CONTENT_OW DATA_TS SYS_LOB0000203779C00 LOB 46 .16 CONTENT_OW DATA_TS SYS_LOB0000203796C00 LOB 41 .14
Direct Writes 直接路径写, 单位额为块数*次数
%Total 为(该段上发生的直接路径写 /physical writes direct )
11-11 Segments by Table Scans
Segments by Table Scans DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> Total Table Scans: 10,713 -> Captured Segments account for 1.0% of Total Tablespace Subobject Obj. Table Owner Name Object Name Name Type Scans %Total ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW DATA_TS MZ_PUBLICATION TABLE 92 .86 CONTENT_OW DATA_TS MZ_CS_WORK_PENDING_R TABLE 14 .13 CONTENT_OW SONG_TS MZ_SONG TABLE 3 .03 CONTENT_OW DATA_TS MZ_AM_REQUEST TABLE 1 .01
Table Scans 来源为dba_hist_seg_stat.table_scans_delta 不过这个指标并不十分精确
11-12 Segments by DB Blocks Changes
Segments by DB Blocks Changes DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> % of Capture shows % of DB Block Changes for each top segment compared -> with total DB Block Changes for all segments captured by the Snapshot Tablespace Subobject Obj. DB Block % of Owner Name Object Name Name Type Changes Capture ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW INDEX_TS MZ_AM_REQUEST_IX8 INDEX 347,856 10.21 CONTENT_OW INDEX_TS MZ_AM_REQUEST_IX3A INDEX 269,504 7.91 CONTENT_OW INDEX_TS MZ_AM_REQUEST_PK INDEX 251,904 7.39 CONTENT_OW DATA_TS MZ_AM_REQUEST TABLE 201,056 5.90 CONTENT_OW INDEX_TS MZ_PRODUCT_ATTRIBUTE INDEX 199,888 5.86
DB Block Changes ,单位为块数*次数
%Total : (该段上发生block changes / db block changes )
11-13 Segments by Row Lock Waits
Segments by Row Lock Waits DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> % of Capture shows % of row lock waits for each top segment compared -> with total row lock waits for all segments captured by the Snapshot Row Tablespace Subobject Obj. Lock % of Owner Name Object Name Name Type Waits Capture ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW LOB_8K_TS MZ_ASSET_WORK_EVENT_ INDEX 72,005 43.86 CONTENT_OW LOB_8K_TS MZ_CS_WORK_NOTE_RE_I _2013_1_36 INDEX 13,795 8.40 CONTENT_OW LOB_8K_TS MZ_CS_WORK_INFO_PART _2013_5_35 INDEX 12,383 7.54 CONTENT_OW INDEX_TS MZ_AM_REQUEST_IX3A INDEX 8,937 5.44 CONTENT_OW DATA_TS MZ_AM_REQUEST TABLE 8,531 5.20
Row Lock Waits 是指行锁的等待次数 数据来源于 dba_hist_seg_stat.ROW_LOCK_WAITS_DELTA
11-14 Segments by ITL WAITS
Segments by ITL Waits DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> % of Capture shows % of ITL waits for each top segment compared -> with total ITL waits for all segments captured by the Snapshot Tablespace Subobject Obj. ITL % of Owner Name Object Name Name Type Waits Capture ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW LOB_8K_TS MZ_ASSET_WORK_EVENT_ INDEX 95 30.16 CONTENT_OW LOB_8K_TS MZ_CS_WORK_NOTE_RE_I _2013_1_36 INDEX 48 15.24 CONTENT_OW LOB_8K_TS MZ_CS_WORK_INFO_PART _2013_5_35 INDEX 21 6.67 CONTENT_OW INDEX_TS MZ_SALABLE_FIRST_AVA INDEX 21 6.67 CONTENT_OW DATA_TS MZ_CS_WORK_PENDING_R TABLE 20 6.35
关于 ITL的介绍详见: http://www.askmaclean.com/archives/enqueue-tx-row-lock-index-itl-wait-event.html
ITL Waits 等待 ITL 的次数,数据来源为 dba_hist_seg_stat.itl_waits_delta
11-14 Segments by Buffer Busy Waits
Segments by Buffer Busy Waits DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> % of Capture shows % of Buffer Busy Waits for each top segment compared -> with total Buffer Busy Waits for all segments captured by the Snapshot Buffer Tablespace Subobject Obj. Busy % of Owner Name Object Name Name Type Waits Capture ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW LOB_8K_TS MZ_ASSET_WORK_EVENT_ INDEX 251,073 57.07 CONTENT_OW LOB_8K_TS MZ_CS_WORK_NOTE_RE_I _2013_1_36 INDEX 36,186 8.23 CONTENT_OW LOB_8K_TS MZ_CS_WORK_INFO_PART _2013_5_35 INDEX 31,786 7.23 CONTENT_OW INDEX_TS MZ_AM_REQUEST_IX3A INDEX 15,663 3.56 CONTENT_OW INDEX_TS MZ_CS_WORK_PENDING_R INDEX 11,087 2.52
Buffer Busy Waits 该数据段上发生 buffer busy wait的次数 数据来源 dba_hist_seg_stat.buffer_busy_waits_delta
11-15 Segments by Global Cache Buffer
Segments by Global Cache Buffer BusyDB/Inst: MAC/MAC2 Snaps: 70719-7072 -> % of Capture shows % of GC Buffer Busy for each top segment compared -> with GC Buffer Busy for all segments captured by the Snapshot GC Tablespace Subobject Obj. Buffer % of Owner Name Object Name Name Type Busy Capture ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW INDEX_TS MZ_AM_REQUEST_IX3 INDEX 2,135,528 50.07 CONTENT_OW DATA_TS MZ_CONTENT_PROVIDER_ TABLE 652,900 15.31 CONTENT_OW LOB_8K_TS MZ_ASSET_WORK_EVENT_ INDEX 552,161 12.95 CONTENT_OW LOB_8K_TS MZ_CS_WORK_NOTE_RE_I _2013_1_36 INDEX 113,042 2.65 CONTENT_OW LOB_8K_TS MZ_CS_WORK_INFO_PART _2013_5_35 INDEX 98,134 2.30
GC Buffer Busy 数据段上发挥僧gc buffer busy的次数, 数据源 dba_hist_seg_stat.gc_buffer_busy_delta
11-15 Segments by CR Blocks Received
Segments by CR Blocks Received DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> Total CR Blocks Received: 763,037 -> Captured Segments account for 40.9% of Total CR Tablespace Subobject Obj. Blocks Owner Name Object Name Name Type Received %Total ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW DATA_TS MZ_AM_REQUEST TABLE 69,100 9.06 CONTENT_OW DATA_TS MZ_CS_WORK_PENDING_R TABLE 44,491 5.83 CONTENT_OW INDEX_TS MZ_AM_REQUEST_IX3A INDEX 36,830 4.83 CONTENT_OW DATA_TS MZ_PODCAST TABLE 36,632 4.80 CONTENT_OW INDEX_TS MZ_AM_REQUEST_PK INDEX 19,646 2.57
CR Blocks Received :是指RAC中本地节点接收到global cache CR blocks 的数量; 数据来源为 dba_hist_seg_stat.gc_cu_blocks_received_delta
%Total : (该段上在本节点接收的Global CR blocks / gc cr blocks received )
11-16 Segments by Current Blocks Received
Segments by Current Blocks ReceivedDB/Inst: MAC/MAC2 Snaps: 70719-70723 -> Total Current Blocks Received: 704,731 -> Captured Segments account for 61.8% of Total Current Tablespace Subobject Obj. Blocks Owner Name Object Name Name Type Received %Total ---------- ---------- -------------------- ---------- ----- ------------ ------- CONTENT_OW INDEX_TS MZ_AM_REQUEST_IX3 INDEX 56,287 7.99 CONTENT_OW INDEX_TS MZ_AM_REQUEST_IX3A INDEX 45,139 6.41 CONTENT_OW DATA_TS MZ_AM_REQUEST TABLE 40,350 5.73 CONTENT_OW DATA_TS MZ_CS_WORK_PENDING_R TABLE 22,808 3.24 CONTENT_OW INDEX_TS MZ_AM_REQUEST_IX8 INDEX 13,343 1.89
Current Blocks Received :是指RAC中本地节点接收到global cache Current blocks 的数量 ,数据来源DBA_HIST_SEG_STAT.gc_cu_blocks_received_delta
%Total : (该段上在本节点接收的 global cache current blocks / gc current blocks received)
12 Dictionary Cache Stats
Dictionary Cache Stats DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> "Pct Misses" should be very low (< 2% in most cases) -> "Final Usage" is the number of cache entries being used Get Pct Scan Pct Mod Final Cache Requests Miss Reqs Miss Reqs Usage ------------------------- ------------ ------ ------- ----- -------- ---------- dc_awr_control 87 2.3 0 N/A 6 1 dc_global_oids 1,134 7.8 0 N/A 0 13 dc_histogram_data 6,119,027 0.9 0 N/A 0 11,784 dc_histogram_defs 1,898,714 2.3 0 N/A 0 5,462 dc_object_grants 175 26.9 0 N/A 0 4 dc_objects 10,254,514 0.2 0 N/A 0 3,807 dc_profiles 8,452 0.0 0 N/A 0 2 dc_rollback_segments 3,031,044 0.0 0 N/A 0 1,947 dc_segments 1,812,243 1.4 0 N/A 10 3,595 dc_sequences 15,783 69.6 0 N/A 15,782 20 dc_table_scns 70 2.9 0 N/A 0 1 dc_tablespaces 1,628,112 0.0 0 N/A 0 37 dc_users 2,037,138 0.0 0 N/A 0 52 global database name 7,698 0.0 0 N/A 0 1 outstanding_alerts 264 99.6 0 N/A 8 1 sch_lj_oids 51 7.8 0 N/A 0 1
Dictionary Cache 字典缓存也叫row cache
数据来源为dba_hist_rowcache_summary
Cache 字典缓存类名kqrstcid <=> kqrsttxt cid=3(dc_rollback_segments)
Get Requests 申请获取该数据字典缓存对象的次数 gets
Miss : GETMISSES 申请获取该数据字典缓存对象但 miss的次数
Pct Miss : GETMISSES /Gets , Miss的比例 ,这个pct miss应当非常低 小于2%,否则有出现大量row cache lock的可能
Scan Reqs:扫描申请的次数 ,kqrssc 、kqrpScan 、kqrpsiv时发生scan 会导致扫描数增加 kqrstsrq++(scan requests) ,例如migrate tablespace 时调用 kttm2b函数 为了安全删除uet$中的记录会callback kqrpsiv (used extent cache),实际很少见
Pct Miss:SCANMISSES/SCANS
Mod Reqs: 申请修改字典缓存对象的次数,从上面的数据可以看到dc_sequences的mod reqs很高,这是因为sequence是变化较多的字典对象
Final Usage :包含有有效数据的字典缓存记录的总数 也就是正在被使用的row cache记录 USAGE Number of cache entries that contain valid data
Dictionary Cache Stats (RAC) DB/Inst: MAC/MAC2 Snaps: 70719-70723 GES GES GES Cache Requests Conflicts Releases ------------------------- ------------ ------------ ------------ dc_awr_control 14 2 0 dc_global_oids 88 0 102 dc_histogram_defs 43,518 0 43,521 dc_objects 21,608 17 21,176 dc_profiles 1 0 1 dc_segments 24,974 14 24,428 dc_sequences 25,178 10,644 347 dc_table_scns 2 0 2 dc_tablespaces 165 0 166 dc_users 119 0 119 outstanding_alerts 478 8 250 sch_lj_oids 4 0 4
GES Request kqrstilr total instance lock requests ,通过全局队列服务GES 来申请instance lock的次数
GES request 申请的原因可能是 dump cache object、kqrbfr LCK进程要background free some parent objects释放一些parent objects 等
GES Conflicts kqrstifr instance lock forced-releases , LCK进程以AST方式 释放锁的次数 ,仅出现在kqrbrl中
GES Releases kqrstisr instance lock self-releases ,LCK进程要background free some parent objects释放一些parent objects 时可能自增
上述数据中可以看到仅有dc_sequences 对应的GES Conflicts较多, 对于sequence 使用ordered和non-cache选项会导致RAC中的一个边际效应,即”row cache lock”等待源于DC_SEQUENCES ROW CACHE。 DC_SEQUENCES 上的GETS request、modifications 、GES requests和GES conflict 与引发生成一个新的 sequence number的特定SQL执行频率相关。
在Oracle 10g中,ORDERED Sequence还可能在高并发下造成大量DFS lock Handle 等待,由于bug 5209859
13 Library Cache Activity
Library Cache Activity DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> "Pct Misses" should be very low Get Pct Pin Pct Invali- Namespace Requests Miss Requests Miss Reloads dations --------------- ------------ ------ -------------- ------ ---------- -------- ACCOUNT_STATUS 8,436 0.3 0 N/A 0 0 BODY 8,697 0.7 15,537 0.7 49 0 CLUSTER 317 4.7 321 4.7 0 0 DBLINK 9,212 0.1 0 N/A 0 0 EDITION 4,431 0.0 8,660 0.0 0 0 HINTSET OBJECT 1,027 9.5 1,027 14.4 0 0 INDEX 792 18.2 792 18.2 0 0 QUEUE 10 0.0 1,733 0.0 0 0 RULESET 0 N/A 8 87.5 7 0 SCHEMA 8,169 0.0 0 N/A 0 0 SQL AREA 533,409 4.8 -4,246,727,944 101.1 44,864 576 SQL AREA BUILD 71,500 65.5 0 N/A 0 0 SQL AREA STATS 41,008 90.3 41,008 90.3 1 0 TABLE/PROCEDURE 320,310 0.6 1,033,991 3.6 25,378 0 TRIGGER 847 0.0 38,442 0.3 110 0
NameSpace library cache 的命名空间
GETS Requests 该命名空间所包含对象的library cache lock被申请的次数
GETHITS 对象的 library cache handle 正好在内存中被找到的次数
Pct Misses : ( 1- ( GETHITS /GETS Requests)) *100
Pin Requests 该命名空间所包含对象上pin被申请的次数
PINHITS 要pin的对象的heap metadata正好在shared pool中的次数
Pct Miss ( 1- ( PINHITS /Pin Requests)) *100
Reloads 指从object handle 被重建开始不是第一次PIN该对象的PIN ,且该次PIN要求对象从磁盘上读取加载的次数 ;Reloads值较高的情况 建议增大shared_pool_size
INVALIDATIONS 由于以来对象被修改导致该命名空间所包含对象被标记为无效的次数
Library Cache Activity (RAC) DB/Inst: MAC/MAC2 Snaps: 70719-70723 GES Lock GES Pin GES Pin GES Inval GES Invali- Namespace Requests Requests Releases Requests dations --------------- ------------ ------------ ------------ ----------- ----------- ACCOUNT_STATUS 8,436 0 0 0 0 BODY 0 15,497 15,497 0 0 CLUSTER 321 321 321 0 0 DBLINK 9,212 0 0 0 0 EDITION 4,431 4,431 4,431 0 0 HINTSET OBJECT 1,027 1,027 1,027 0 0 INDEX 792 792 792 0 0 QUEUE 8 1,733 1,733 0 0 RULESET 0 8 8 0 0 SCHEMA 4,226 0 0 0 0 TABLE/PROCEDURE 373,163 704,816 704,816 0 0 TRIGGER 0 38,430 38,430 0 0
GES Lock Request: dlm_lock_requests Lock instance-lock ReQuests 申请获得lock instance lock的次数
GES PIN request : DLM_PIN_REQUESTS Pin instance-lock ReQuests 申请获得pin instance lock的次数
GES Pin Releases DLM_PIN_RELEASES release the pin instance lock 释放pin instance lock的次数
GES Inval Requests DLM_INVALIDATION_REQUESTS get the invalidation instance lock 申请获得invalidation instance lock的次数
GES Invali- dations DLM_INVALIDATIONS 接收到其他节点的invalidation pings次数
14 Process Memory Summary
Process Memory Summary DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> B: Begin Snap E: End Snap -> All rows below contain absolute values (i.e. not diffed over the interval) -> Max Alloc is Maximum PGA Allocation size at snapshot time -> Hist Max Alloc is the Historical Max Allocation for still-connected processes -> ordered by Begin/End snapshot, Alloc (MB) desc Hist Avg Std Dev Max Max Alloc Used Alloc Alloc Alloc Alloc Num Num Category (MB) (MB) (MB) (MB) (MB) (MB) Proc Alloc - -------- --------- --------- -------- -------- ------- ------- ------ ------ B Other 16,062.7 N/A 6.1 66.6 3,370 3,370 2,612 2,612 SQL 5,412.2 4,462.9 2.2 89.5 4,483 4,483 2,508 2,498 Freeable 2,116.4 .0 .9 6.3 298 N/A 2,266 2,266 PL/SQL 94.0 69.8 .0 .0 1 1 2,610 2,609 E Other 15,977.3 N/A 6.1 66.9 3,387 3,387 2,616 2,616 SQL 5,447.9 4,519.0 2.2 89.8 4,505 4,505 2,514 2,503 Freeable 2,119.9 .0 .9 6.3 297 N/A 2,273 2,273 PL/SQL 93.2 69.2 .0 .0 1 1 2,614 2,613
数据来源为dba_hist_process_mem_summary, 这里是对PGA 使用的一个小结,帮助我们了解到底谁用掉了PGA
B: 开始快照 E: 结束快照
该环节列出 PGA中各分类的使用量
Category 分类名,包括”SQL”, “PL/SQL”, “OLAP” 和”JAVA”. 特殊分类是 “Freeable” 和”Other”. Free memory是指哪些 OS已经分配给进程,但没有分配给任何分类的内存。 “Other”是已经分配给分类的内存,但不是已命名的分类
Alloc (MB) allocated_total 该分类被分配的总内存
Used (MB) used_total 该分类已使用的内存
Avg Alloc (MB) allocated_avg 平均每个进程中该分类分配的内存量
Std Dev Alloc (MB) :该分类分配的内存在每个进程之间的标准差
Max Alloc (MB) ALLOCATED_MAX :在快照时间内单个进程该分类最大分配过的内存量:Max Alloc is Maximum PGA Allocation size at snapshot time
Hist Max Alloc (MB) MAX_ALLOCATED_MAX: 目前仍链接着的进程该分类最大分配过的内存量:Hist Max Alloc is the Historical Max Allocation for still-connected processes
Num Proc num_processes 进程数目
Num Alloc NON_ZERO_ALLOCS 分配了该类型 内存的进程数目
14 SGA信息
14 -1 SGA Memory Summary
SGA Memory Summary DB/Inst: MAC/MAC2 Snaps: 70719-70723 End Size (Bytes) SGA regions Begin Size (Bytes) (if different) ------------------------------ ------------------- ------------------- Database Buffers 20,669,530,112 Fixed Size 2,241,880 Redo Buffers 125,669,376 Variable Size 10,536,094,376 ------------------- sum 31,333,535,744
粗粒度的sga区域内存使用信息, End Size仅在于begin size不同时打印
14-2 SGA breakdown difference
SGA breakdown difference DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> ordered by Pool, Name -> N/A value for Begin MB or End MB indicates the size of that Pool/Name was insignificant, or zero in that snapshot Pool Name Begin MB End MB % Diff ------ ------------------------------ -------------- -------------- ------- java free memory 64.0 64.0 0.00 large PX msg pool 7.8 7.8 0.00 large free memory 247.8 247.8 0.00 shared Checkpoint queue 140.6 140.6 0.00 shared FileOpenBlock 2,459.2 2,459.2 0.00 shared KGH: NO ACCESS 1,629.6 1,629.6 0.00 shared KGLH0 997.7 990.5 -0.71 shared KKSSP 312.2 308.9 -1.06 shared SQLA 376.6 370.6 -1.61 shared db_block_hash_buckets 178.0 178.0 0.00 shared dbktb: trace buffer 156.3 156.3 0.00 shared event statistics per sess 187.1 187.1 0.00 shared free memory 1,208.9 1,220.6 0.97 shared gcs resources 435.0 435.0 0.00 shared gcs shadows 320.6 320.6 0.00 shared ges enqueues 228.9 228.9 0.00 shared ges resource 118.3 118.3 0.00 shared init_heap_kfsg 1,063.6 1,068.1 0.43 shared kglsim object batch 124.3 124.3 0.00 shared ksunfy : SSO free list 174.7 174.7 0.00 stream free memory 128.0 128.0 0.00 buffer_cache 19,712.0 19,712.0 0.00 fixed_sga 2.1 2.1 0.00 log_buffer 119.8 119.8 0.00 -------------------------------------------------------------
Pool 内存池的名字
Name 内存池中细分组件的名字 例如KGLH0 存放KEL Heap 0 、SQLA存放SQL执行计划等
Begin MB 快照开始时该组件的内存大小
End MB 快照结束时该组件的内存大小
% Diff 差异百分比
特别注意 由于AMM /ASMM引起的shared pool收缩 一般在sga breakdown中可以提现 例如SQLA 、KQR等组件大幅缩小 ,可能导致一系列的解析等待 cursor: Pin S on X 、row cache lock等
此处的free memory信息也值得我们关注, 一般推荐shared pool应当有300~400 MB 的free memory为宜
15 Streams统计
Streams CPU/IO Usage DB/Inst: ORCL/orcl1 Snaps: 556-559 -> Streams processes ordered by CPU usage -> CPU and I/O Time in micro seconds Session Type CPU Time User I/O Time Sys I/O Time ------------------------- -------------- -------------- -------------- QMON Coordinator 101,698 0 0 QMON Slaves 63,856 0 0 ------------------------------------------------------------- Streams Capture DB/Inst: CATGT/catgt Snaps: 911-912 -> Lag Change should be small or negative (in seconds) Captured Enqueued Pct Pct Pct Pct Per Per Lag RuleEval Enqueue RedoWait Pause Capture Name Second Second Change Time Time Time Time ------------ -------- -------- -------- -------- -------- -------- -------- CAPTURE_CAT 650 391 93 0 23 0 71 ------------------------------------------------------------- Streams Apply DB/Inst: CATGT/catgt Snaps: 911-912 -> Pct DB is the percentage of all DB transactions that this apply handled -> WDEP is the wait for dependency -> WCMT is the wait for commit -> RBK is rollbacks -> MPS is messages per second -> TPM is time per message in milli-seconds -> Lag Change should be small or negative (in seconds) Applied Pct Pct Pct Pct Applied Dequeue Apply Lag Apply Name TPS DB WDEP WCMT RBK MPS TPM TPM Change ------------ -------- ---- ---- ---- --- -------- -------- -------- -------- APPLY_CAT 0 0 0 0 0 0 0 0 0 -------------------------------------------------------------
Capture Name : Streams捕获进程名
Captured Per Second :每秒挖掘出来的message 条数
Enqueued Per Second: 每秒入队的message条数
lag change: 指日志生成的时间到挖掘到该日志生成 message的时间延迟
Pct Enqueue Time: 入队时间的比例
Pct redoWait Time : 等待redo的时间比例
Pct Pause Time : Pause 时间的比例
Apply Name Streams 应用Apply进程的名字
Applied TPS : 每秒应用的事务数
Pct DB: 所有的DB事务中 apply处理的比例
Pct WDEP: 由于等待依赖的数据而耗费的时间比例
Pct WCMT: 由于等待commit而耗费的时间比例
Pct RBK: 事务rollback 回滚的比例
Applied MPS: 每秒应用的message 数
Dequeue TPM: 每毫秒出队的message数
Lag Change:指最新message生成的时间到其被Apply收到的延迟
16 Resource Limit
Resource Limit Stats DB/Inst: MAC/MAC2 Snap: 70723 -> only rows with Current or Maximum Utilization > 80% of Limit are shown -> ordered by resource name Current Maximum Initial Resource Name Utilization Utilization Allocation Limit ------------------------------ ------------ ------------ ---------- ---------- ges_procs 2,612 8,007 10003 10003 processes 2,615 8,011 10000 10000
数据源于dba_hist_resource_limit
注意这里仅列出当前使用或最大使用量>80% *最大限制的资源名,如果没有列在这里则说明 资源使用量安全
Current Utilization 当前对该资源(包括Enqueue Resource、Lock和processes)的使用量
Maximum Utilization 从最近一次实例启动到现在该资源的最大使用量
Initial Allocation 初始分配值,一般等于参数文件中指定的值
Limit 实际上限值
17 init.ora Parameters
init.ora Parameters DB/Inst: MAC/MAC2 Snaps: 70719-70723 End value Parameter Name Begin value (if different) ----------------------------- --------------------------------- -------------- _compression_compatibility 11.2.0 _kghdsidx_count 4 _ksmg_granule_size 67108864 _shared_pool_reserved_min_all 4100 archive_lag_target 900 audit_file_dest /u01/app/oracle/admin/MAC/adum audit_trail OS cluster_database TRUE compatible 11.2.0.2.0 control_files +DATA/MAC/control01.ctl, +RECO db_16k_cache_size 268435456 db_block_size 8192 db_cache_size 19327352832 db_create_file_dest +DATA
Parameter Name 参数名
Begin value 开始快照时的参数值
End value 结束快照时的参数值 (仅在发生变化时打印)
18 Global Messaging Statistics
Global Messaging Statistics DB/Inst: MAC/MAC2 Snaps: 70719-70723 Statistic Total per Second per Trans --------------------------------- ---------------- ------------ ------------ acks for commit broadcast(actual) 53,705 14.9 0.2 acks for commit broadcast(logical 311,182 86.1 1.3 broadcast msgs on commit(actual) 317,082 87.7 1.3 broadcast msgs on commit(logical) 317,082 87.7 1.3 broadcast msgs on commit(wasted) 263,332 72.9 1.1 dynamically allocated gcs resourc 0 0.0 0.0 dynamically allocated gcs shadows 0 0.0 0.0 flow control messages received 267 0.1 0.0 flow control messages sent 127 0.0 0.0 gcs apply delta 0 0.0 0.0 gcs assume cvt 55,541 15.4 0.2
全局通信统计信息,数据来源WRH$_DLM_MISC;
20 Global CR Served Stats
Global CR Served Stats DB/Inst: MAC/MAC2 Snaps: 70719-70723 Statistic Total ------------------------------ ------------------ CR Block Requests 403,703 CURRENT Block Requests 444,896 Data Block Requests 403,705 Undo Block Requests 94,336 TX Block Requests 307,896 Current Results 652,746 Private results 21,057 Zero Results 104,720 Disk Read Results 69,418 Fail Results 508 Fairness Down Converts 102,844 Fairness Clears 15,207 Free GC Elements 0 Flushes 105,052 Flushes Queued 0 Flush Queue Full 0 Flush Max Time (us) 0 Light Works 71,793 Errors 117
LMS传输CR BLOCK的统计信息,数据来源WRH$_CR_BLOCK_SERVER
21 Global CURRENT Served Stats
Global CURRENT Served Stats DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> Pins = CURRENT Block Pin Operations -> Flushes = Redo Flush before CURRENT Block Served Operations -> Writes = CURRENT Block Fusion Write Operations Statistic Total % <1ms % <10ms % <100ms % <1s % <10s ---------- ------------ -------- -------- -------- -------- -------- Pins 73,018 12.27 75.96 8.49 2.21 1.08 Flushes 79,336 5.98 50.17 14.45 19.45 9.95 Writes 102,189 3.14 35.23 19.34 33.26 9.03
数据来源dba_hist_current_block_server
Time to process current block request = (pin time + flush time + send time)
Pins CURRENT Block Pin Operations , PIN的内涵是处理一个BAST 不包含对global current block的flush和实际传输
The pin time represents how much time is required to process a BAST. It does not include the flush time and
the send time. The average pin time per block served should be very low because the processing consists
mainly of code path and should never be blocked.
Flush 指 脏块被LMS进程传输出去之前,其相关的redo必须由LGWR已经flush 到磁盘上
Write 指fusion write number of writes which were mediated; 节点之间写脏块需求相互促成的行为 KJBL.KJBLREQWRITE gcs write request msgs 、gcs writes refused
% <1ms % <10ms % <100ms % <1s % <10s 分别对应为pin、flush、write行为耗时的比例
例如在上例中flush和 write 在1s 到10s之间的有9%,在100ms 和1s之间的有19%和33%,因为flush和write都是IO操作 所以这里可以预见IO存在问题,延迟较高
22 Global Cache Transfer Stats
Global Cache Transfer Stats DB/Inst: MAC/MAC2 Snaps: 70719-70723 -> Immediate (Immed) - Block Transfer NOT impacted by Remote Processing Delays -> Busy (Busy) - Block Transfer impacted by Remote Contention -> Congested (Congst) - Block Transfer impacted by Remote System Load -> ordered by CR + Current Blocks Received desc CR Current ----------------------------- ----------------------------- Inst Block Blocks % % % Blocks % % % No Class Received Immed Busy Congst Received Immed Busy Congst ---- ----------- -------- ------ ------ ------ -------- ------ ------ ------ 1 data block 133,187 76.3 22.6 1.1 233,138 75.2 23.0 1.7 4 data block 143,165 74.1 24.9 1.0 213,204 76.6 21.8 1.6 3 data block 122,761 75.9 23.0 1.1 220,023 77.7 21.0 1.3 1 undo header 104,219 95.7 3.2 1.1 941 93.4 5.8 .7 4 undo header 95,823 95.2 3.7 1.1 809 93.4 5.3 1.2 3 undo header 95,592 95.6 3.3 1.1 912 94.6 4.5 .9 1 undo block 25,002 95.8 3.4 .9 0 N/A N/A N/A 4 undo block 23,303 96.0 3.1 .9 0 N/A N/A N/A 3 undo block 21,672 95.4 3.7 .9 0 N/A N/A N/A 1 Others 1,909 92.0 6.8 1.2 6,057 89.6 8.9 1.5 4 Others 1,736 92.4 6.1 1.5 5,841 88.8 9.9 1.3 3 Others 1,500 92.4 5.9 1.7 4,405 87.7 10.8 1.6
数据来源DBA_HIST_INST_CACHE_TRANSFER
Inst No 节点号
Block Class 块的类型
CR Blocks Received 该节点上 该类型CR 块的接收数量
CR Immed %: CR块请求立即接收到的比例
CR Busy%:CR块请求由于远端争用而没有立即接收到的比例
CR Congst%: CR块请求由于远端负载高而没有立即接收到的比例
Current Blocks Received 该节点上 该类型Current 块的接收数量
Current Immed %: Current块请求立即接收到的比例
Current Busy%:Current块请求由于远端争用而没有立即接收到的比例
Current Congst%: Current块请求由于远端负载高而没有立即接收到的比例
Congst%的比例应当非常低 不高于2%, Busy%很大程度受到IO的影响,如果超过10% 一般会有严重的gc buffer busy acquire/release
参考文档
Statistics Descriptions http://docs.oracle.com/cd/B19306_01/server.102/b14237/stats002.htm
Memory Configuration and Use http://docs.oracle.com/cd/B19306_01/server.102/b14211/memory.htm
Library Cache Hit (%) http://docs.oracle.com/cd/B16240_01/doc/doc.102/e16282/oracle_database_help/oracle_database_instance_efficiency_libcache_hit_pct.html
Oracle® Database Performance Tuning Guide 12c Release 1 (12.1)
How to Interpret the “SQL ordered by Physical Reads (UnOptimized)” Section in AWR Reports (11.2 onwards) [ID 1466035.1]
FILED UNDER: ORACLE, ORACLE SQL性能调优
【Oracle Database 12c新特性】DROP Index/CONSTRAINT ONLINE
2013/08/31 BY MACLEAN LIU 暂无评论
12c中提供了DROP Index/CONSTRAINT ONLINE的新特性, ONLINE意味着在drop index期间对于表或分区的DML操作不被阻塞。
DROP INDEX ONLINE对于分区索引或者非分区索引均可用。
在12c drop index online之前普通的drop index操作会可能导致短暂的enq: TM 等待,原因是
SQL> select * from v$version; BANNER ---------------------------------------------------------------- Oracle Database 10g Enterprise Edition Release 10.2.0.5.0 - 64bi PL/SQL Release 10.2.0.5.0 - Production CORE 10.2.0.5.0 Production TNS for Linux: Version 10.2.0.5.0 - Production NLSRTL Version 10.2.0.5.0 - Production SQL> SQL> create table DML_ONLINE as select * from dba_tables; Table created. SQL> create index idx_name on DML_ONLINE(table_name); Index created. SQL> alter session set events ‘10704 trace name context forever , level 10‘; Session altered. SQL> drop index idx_name ; Index dropped. SQL> select object_id from dba_objects where object_name=‘DML_ONLINE‘; OBJECT_ID ---------- 97302 97302=>17C16 SQL> oradebug setmypid Statement processed. SQL> oradebug tracefile_name /s01/admin/G10R25/udump/g10r25_ora_7007.trc [[email protected] ~]$ grep "ksqgtl \*\*\*" /s01/admin/G10R25/udump/g10r25_ora_7007.trc ksqgtl *** TX-00080027-000021d4 mode=6 flags=0x401 timeout=0 *** ksqgtl *** TM-00017c16-00000000 mode=6 flags=0x401 timeout=0 *** ksqgtl *** TM-00000318-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** CU-92e387e8-00000000 mode=6 flags=0x10 timeout=300 *** ksqgtl *** TM-0000023a-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000049-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000004a-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000004b-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000004c-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-000002d8-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000039-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** CU-92e37c98-00000000 mode=6 flags=0x10 timeout=300 *** ksqgtl *** CU-92e37c98-00000000 mode=6 flags=0x10 timeout=300 *** ksqgtl *** TM-00000014-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** CU-92e377a8-00000000 mode=6 flags=0x10 timeout=300 *** ksqgtl *** CU-92e377a8-00000000 mode=6 flags=0x10 timeout=300 *** ksqgtl *** TM-00000013-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000000e-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000012-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TS-00000000-00414641 mode=6 flags=0x11 timeout=0 *** ksqgtl *** TT-00000000-00000010 mode=4 flags=0x11 timeout=21474836 *** ksqgtl *** RO-00010014-00000001 mode=6 flags=0x11 timeout=21474836 *** ksqgtl *** RO-00010014-00000002 mode=1 flags=0x11 timeout=21474836 *** ksqgtl *** TM-0000000e-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TX-00010018-00001cbc mode=6 flags=0x401 timeout=0 *** ksqgtl *** TX-00030006-00002417 mode=6 flags=0x401 timeout=0 *** ksqgtl *** CI-00000001-00000005 mode=6 flags=0x10 timeout=21474836 *** ksqgtl *** TM-0000000e-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** CU-92e372b8-00000000 mode=6 flags=0x10 timeout=300 *** 97302=>17C16 ksqgtl *** TM-00017c16-00000000 mode=6 这里可以看到 drop index 期间拿了对应表的TM mode=6 exclusive mode table lock
如果使用12c 中的drop index Online则:
SQL> select banner from v$version where rownum=1; BANNER -------------------------------------------------------------------------------- Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 - 64bit Production SQL> create table DML_ONLINE as select * from dba_tables; 表已创建。 SQL> create index idx_name on DML_ONLINE(table_name); 索引已创建。 SQL> alter session set events ‘10704 trace name context forever , level 10‘; 会话已更改。 SQL> drop index idx_name online ; 索引已删除。 SQL> select object_id from dba_objects where object_name=‘DML_ONLINE‘; OBJECT_ID ---------- 117648 SQL> oradebug setmypid 已处理的语句 SQL> oradebug tracefile_name maclean_ora_1212.trc [[email protected] ~]$ grep "ksqgtl \*\*\*" maclean_ora_1212.trc [[email protected] ~]$ grep "ksqgtl \*\*\*" maclean_ora_4280.trc ksqgtl *** CU-0FE14E98-000007FF-00000000-00000000 mode=6 flags=0x10000 timeout=300 *** ksqgtl *** TM-0001CB90-00000000-00000000-00000000 mode=2 flags=0x401 timeout=0 *** ksqgtl *** OD-0001CB90-00000000-00000000-00000000 mode=4 flags=0x10401 timeout=0 *** ksqgtl *** OD-0001CB91-00000000-00000000-00000000 mode=6 flags=0x10401 timeout=0 *** ksqgtl *** TM-0001CB90-00000000-00000000-00000000 mode=2 flags=0x401 timeout=0 *** ksqgtl *** CU-0FE103C8-000007FF-00000000-00000000 mode=6 flags=0x10000 timeout=300 *** ksqgtl *** CU-0FE103C8-000007FF-00000000-00000000 mode=6 flags=0x10000 timeout=300 *** ksqgtl *** TM-0000004B-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** CU-0FE07708-000007FF-00000000-00000000 mode=6 flags=0x10000 timeout=300 *** ksqgtl *** CU-0FE07708-000007FF-00000000-00000000 mode=6 flags=0x10000 timeout=300 *** ksqgtl *** TM-00000013-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TX-00090010-00000C08-00000000-00000000 mode=6 flags=0x401 timeout=0 *** ksqgtl *** TM-00000012-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TX-00030006-00000D1A-00000000-00000000 mode=6 flags=0x401 timeout=0 *** ksqgtl *** CU-0FDFABF8-000007FF-00000000-00000000 mode=6 flags=0x10000 timeout=300 *** ksqgtl *** TM-00000224-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00001569-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000004D-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000265-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000007F-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-000000EB-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-000000ED-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-000000F3-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000026C-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000142-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000143-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000123-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-000002AF-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000146-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000127-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000128-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000129-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000012A-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000138-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000003D-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000014-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000013-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000000E-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000012-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TS-00000000-00419660-00000000-00000000 mode=6 flags=0x10001 timeout=0 *** ksqgtl *** TT-00000000-00000010-00000000-00000000 mode=4 flags=0x10001 timeout=21474836 *** ksqgtl *** TS-00000000-00419661-00000000-00000000 mode=6 flags=0x10001 timeout=21474836 *** ksqgtl *** RO-00010038-00000001-00000000-00000000 mode=6 flags=0x10001 timeout=21474836 *** ksqgtl *** RO-00010038-00000002-00000000-00000000 mode=6 flags=0x10001 timeout=21474836 *** ksqgtl *** TM-0000000E-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TX-00040014-00000BB2-00000000-00000000 mode=6 flags=0x401 timeout=0 *** ksqgtl *** TX-00090006-00000C0D-00000000-00000000 mode=6 flags=0x401 timeout=0 *** ksqgtl *** CR-00010038-00000001-00000000-00000000 mode=6 flags=0x10001 timeout=21474836 *** ksqgtl *** CR-00010038-00000002-00000000-00000000 mode=6 flags=0x10001 timeout=21474836 *** ksqgtl *** TM-0000000E-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** CU-0FDFA688-000007FF-00000000-00000000 mode=6 flags=0x10000 timeout=300 *** ksqgtl *** MC-00000000-87EFB967-00000000-00000000 mode=4 flags=0x10001 timeout=21474836 *** [[email protected] ~]$ grep "ksqgtl \*\*\*" maclean_ora_4280.trc |grep TM- ksqgtl *** TM-0001CB90-00000000-00000000-00000000 mode=2 flags=0x401 timeout=0 *** ksqgtl *** TM-0001CB90-00000000-00000000-00000000 mode=2 flags=0x401 timeout=0 *** ksqgtl *** TM-0000004B-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000013-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000012-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000224-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00001569-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000004D-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000265-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000007F-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-000000EB-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-000000ED-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-000000F3-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000026C-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000142-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000143-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000123-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-000002AF-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000146-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000127-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000128-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000129-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000012A-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000138-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000003D-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000014-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000013-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000000E-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-00000012-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000000E-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** ksqgtl *** TM-0000000E-00000000-00000000-00000000 mode=3 flags=0x401 timeout=21474836 *** 117648=> 1CB90 可以看到 drop index online之后只 获取了 mode=2 SS的 TM lock TM-0001CB90-00000000-00000000-00000000 mode=2
类似于 INDEX , 12c中还提供了 DROP CONSTRAINT ONLINE的新特性, 允许在线drop 约束; 但是存在如下限制:
- Cannot drop a constraint with CASCADE
- Cannot drop a referencing constraint
具体语法如下:
ALTER TABLE hr.employees DROP CONSTRAINT emp_email_uk ONLINE;
这2中 ONLINE DROP 新特性 究其根本都是在DROP 过程中不在acquire TM mode=6的表队列锁,虽然这些操作本身的耗时并不久,也就不会长时间阻塞DML ,但是对于高并发的OLTP系统而言 阻塞仍可能是致命的。
FILED UNDER: ORACLE, ORACLE 12C新特性
V$RECOVERY_PROGRESS For Oracle Recovery
2013/08/30 BY MACLEAN LIU 暂无评论
V$RECOVERY_PROGRESS For Oracle Recovery
V$RECOVERY_PROGRESS view
Major overhaul for Media Recovery and Physical Standby in 10gR2
Tracks redo apply rate: overall and recent
Breakdown of apply vs. checkpoint time per log
Recovery performance can be monitored using V$RECOVERY_PROGRESS and several system events
and stats. However, more work is needed in this space to help discover which parts of the recovery
algorithm are taking a long time. The discussion here mainly applies to RDBMS Release 11.2, but can
also be applicable for future releases. Below, new stats are described in bold-faced.
more info: http://emrebaransel.blogspot.jp/2010/06/mrp-speed-log-apply-rate-of-standby.html
FILED UNDER: ORACLE, ORACLE DATA GUARD STANDBY
补丁集Patch Set 11.2.0.4 来了!
2013/08/28 BY MACLEAN LIU 1条评论
#ORACLE DATABASE PATCHSET# Oracle 11gR2重要更新 Patchset 11.2.0.4 已经release ,补丁号 patch 13390677. 相关文档Note 742060.1 . 11.2.0.4的新特性请参考这里 http://t.cn/z82pt6W 新特性包括 Trace File Analyzer (TFA) 和 RACcheck ; 11.2.0.4 来了!
FILED UNDER: ORACLE, ORACLE 11G新特性
_use_adaptive_log_file_sync know more
2013/08/27 BY MACLEAN LIU 暂无评论
Configuration Parameters
The following parameters affect the behavior of adaptive log file sync:
- _use_adaptive_log_file_sync
- TRUE: Enable adaptive log file sync (default)
- FALSE: Disable adaptive log file sync (i.e., just use post/wait)
- POLLING_ONLY: Use polling with adaptive polling interval
- _adaptive_log_file_sync_use_polling_threshold
- Larger values make it harder to switch to polling
- Default value is 110%, which means the current redo synch time must exceed the expected poll time
- by at least 10% for the algorithm to favor polling over post/wait
- In the pseudocode above, refer to the use_polling_threshold variable
- _adaptive_log_file_sync_use_postwait_threshold
- Smaller values make it harder to switch to post/wait
- Default value is 50%, which means the current scheduling delay needs to drop to half of that when
- polling was first used for the algorithm to favor post/wait over polling
- In the pseudocode above, refer to the use_postwait_threshold variable
- _adaptive_log_file_sync_poll_aggressiveness
- Larger values result in smaller polling intervals
- Default value is 0%, which means none of the current scheduling delay is subtracted from the polling interval
- _adaptive_log_file_sync_sched_delay_window
- The window over which the current scheduling delay is computed
- Default value is 60 seconds, and it is unlikely you need to adjust this
- _adaptive_log_file_sync_high_switch_freq_threshold
- A warning is printed if adaptive log file sync switches frequently between post/wait and polling
- If it is an LRG, a soft assert is also signalled
- Default threshold is 3 switches per minute
- _fg_sync_sleep_usecs
- A non-zero value specified will use polling with a fixed interval and disable adaptive log file sync
- _log_file_sync_timeout
- How long the foreground waits for LGWR to post it when post/wait is used
- Default value is 100 msecs
FILED UNDER: ORACLE
Maclean教你读SQL TRACE TKProf报告
2013/08/25 BY MACLEAN LIU 暂无评论
在《Maclean教你读Oracle 10046 SQL TRACE》中我介绍了10046 TRACE的阅读以及其中个字段的含义, 接着我们介绍 10046 sql trace的搭档工具TKPROF。
TKPROF是一个可执行文件,自带在Oracle Server软件中,无需额外的安装。 该工具文件可以用来解析ORACLE的SQL TRACE(10046) 以便生成更可读的内容。 实际上tkprof是对10046 SQL trace的内容作了汇总,例如一个语句遇到过的wait event 、其在PARSE、Execute、Fetch三阶段的耗时、CPU_TIME等等。
由于tkprof是对10046 SQL TRACE的汇总,所以tkprof中的信息 完全可以从10046中获得, 10046的问题是 由于巨细靡遗 所以TRACE内容可能过多,内容多则难以快速分析, TKPROF将10046 trace 解析过后更适合调优者阅读。
TKPROF的语法如下:
tkprof tracefile outfile [explain=user/password] [options…]
几个选项
print=integer 只列出前几个SQL语句,integer 为指定的数量,例如print=10
sys=no 不列出以SYS用户运行的语句
sort=option 排序选项, 选项列表如下:
- prscnt number of times parse was called
- prscpu cpu time parsing
- prsela elapsed time parsing
- prsdsk number of disk reads during parse
- prsqry number of buffers for consistent read during parse
- prscu number of buffers for current read during parse
- prsmis number of misses in library cache during parse
- execnt number of execute was called
- execpu cpu time spent executing
- exeela elapsed time executing
- exedsk number of disk reads during execute
- exeqry number of buffers for consistent read during execute
- execu number of buffers for current read during execute
- exerow number of rows processed during execute
- exemis number of library cache misses during execute
- fchcnt number of times fetch was called
- fchcpu cpu time spent fetching
- fchela elapsed time fetching
- fchdsk number of disk reads during fetch
- fchqry number of buffers for consistent read during fetch
- fchcu number of buffers for current read during fetch
- fchrow number of rows fetched
- userid userid of user that parsed the cursor
接下来看一个最简单的 TKPROF的例子:
drop table fullscan; create table fullscan as select * from dba_objects; exec dbms_stats.gather_table_stats(user,‘FULLSCAN‘); alter system flush shared_pool; alter system flush buffer_cache; alter session set events ‘10046 trace name context forever,level 12‘; select count(*) from fullscan; oradebug setmypid oradebug tracefile_name; /s01/admin/G10R25/udump/g10r25_ora_30334.trc [[email protected] udump]$ tkprof /s01/admin/G10R25/udump/g10r25_ora_30334.trc 30334.tkf TKPROF: Release 10.2.0.5.0 - Production on Sun Aug 25 02:21:27 2013 askmaclean.com Copyright (c) 1982, 2007, Oracle. All rights reserved. vi 30334.tkf Trace file: /s01/admin/G10R25/udump/g10r25_ora_30334.trc Sort options: default ******************************************************************************** count = number of times OCI procedure was executed cpu = cpu time in seconds executing elapsed = elapsed time in seconds executing disk = number of physical reads of buffers from disk query = number of buffers gotten for consistent read current = number of buffers gotten in current mode (usually for update) rows = number of rows processed by the fetch or execute call ******************************************************************************** select obj#,type#,ctime,mtime,stime,status,dataobj#,flags,oid$, spare1, spare2 from obj$ where owner#=:1 and name=:2 and namespace=:3 and remoteowner is null and linkname is null and subname is null call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 0 0 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 1 0.00 0.00 2 4 0 1 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 3 0.00 0.00 2 4 0 1 Misses in library cache during parse: 1 Misses in library cache during execute: 1 Optimizer mode: CHOOSE Parsing user id: SYS (recursive depth: 1) Rows Row Source Operation ------- --------------------------------------------------- 1 TABLE ACCESS BY INDEX ROWID OBJ$ (cr=4 pr=2 pw=0 time=133 us) 1 INDEX RANGE SCAN I_OBJ2 (cr=3 pr=1 pw=0 time=74 us)(object id 37) Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 1 0.00 0.00 SQL*Net message from client 1 0.01 0.01 db file sequential read 2 0.00 0.00 ******************************************************************************** select count(*) from fullscan call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 4 15 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 2 0.01 0.01 1139 1143 0 1 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 4 0.02 0.02 1143 1158 0 1 Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: SYS Rows Row Source Operation ------- --------------------------------------------------- 1 SORT AGGREGATE (cr=1143 pr=1139 pw=0 time=15759 us) 77268 TABLE ACCESS FULL FULLSCAN (cr=1143 pr=1139 pw=0 time=463719 us) Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 2 0.00 0.00 db file sequential read 1 0.00 0.00 db file scattered read 80 0.00 0.00 SQL*Net message from client 2 0.00 0.00
在上述例子中我们可以看到TKPROF将 一个SQL Statement 的运行 划分为几个部分的信息:
1. SQL 语句的parse 、execute 、fetch 阶段的耗时:
select count(*) from fullscan call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 4 15 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 2 0.01 0.01 1139 1143 0 1 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 4 0.02 0.02 1143 1158 0 1
call: 每一个游标的行为被分成三个步骤:
- Parse: 解析该游标并生成执行计划的统计信息
- Execute: 执行该游标阶段的统计信息
- Fetch : Fetch取得数据行阶段的统计信息
- count 指的是该游标的相关操作 的次数,例如parse count : 2 ,即该游标解析了2次
- CPU : 相关栏目 所消耗的CPU时间,单位为s
- elapsed: 相关栏目所消耗的时间,单位为s
- disk : 相关栏目所消耗的物理读
- query : 相关栏目所消耗的一致性逻辑读 consistent logical read ==>一般对于SELECT查询而言 只有query 没有current
- current: 相关栏目当前逻辑读 current logical read
- rows 该步骤取回的行数 ==》在本例中由于是 count(*) 所以只有一行
- Misses in library cache during parse: 1 在解析阶段 library cache 发生了miss,则说明本次解析是硬解析
几点释疑:
1、对于PL/SQL而言 匿名块/存储过程 以及其中包含的SQL语句会同时体现在TKPROF中,即存在重叠;且SQL将以递归SQL的形式出现:
PARSING IN CURSOR #4 len=56 dep=1 uid=0 oct=6 lid=0 tim=1345130672819745 hv=3509762282 ad=’a7525f30′
UPDATE FULLSCAN SET OWNER=’MACLEAN’ WHERE OBJECT_ID=:B1
COMMIT也是这样:
PARSING IN CURSOR #2 len=6 dep=1 uid=0 oct=44 lid=0 tim=1345130672822889 hv=255718823 ad=’0′
COMMIT
我们来看一个实际的例子:
alter system flush shared_pool; alter system flush buffer_cache; set timing on; alter session set events ‘10046 trace name context forever,level 12‘; create index ind_objd on fullscan(object_id); begin for i in 1..10000 loop update fullscan set owner=‘MACLEAN‘ where object_id=i; commit; end loop; end; / PL/SQL procedure successfully completed. Elapsed: 00:00:04.00 begin for i in 1..10000 loop update fullscan set owner=‘MACLEAN‘ where object_id=i; commit; end loop; end; call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 0 0 0 0 Execute 1 0.62 0.68 178 20037 0 1 Fetch 0 0.00 0.00 0 0 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 2 0.62 0.68 178 20037 0 1 Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: SYS Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ log file sync 1 0.00 0.00 SQL*Net message to client 1 0.00 0.00 ******************************************************************************** UPDATE FULLSCAN SET OWNER=‘MACLEAN‘ WHERE OBJECT_ID=:B1 call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 0 0 0 0 Execute 10000 2.90 2.69 178 20037 19364 9564 Fetch 0 0.00 0.00 0 0 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 10001 2.90 2.69 178 20037 19364 9564 Misses in library cache during parse: 1 Misses in library cache during execute: 1 Optimizer mode: ALL_ROWS Parsing user id: SYS (recursive depth: 1) Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ db file sequential read 177 0.00 0.00 COMMIT call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 0 0 0 0 Execute 10000 0.43 0.52 0 0 9564 0 Fetch 0 0.00 0.00 0 0 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 10001 0.43 0.52 0 0 9564 0 Misses in library cache during parse: 0 Parsing user id: SYS (recursive depth: 1)
以上通过一个匿名块 循环执行了10000次的 “update fullscan set owner=’MACLEAN’ where object_id=i;” 以及commit 总的执行 Elapsed: 00:00:04.00 。
该匿名块总耗时为0.68s, 10000次循环update fullscan为2.69s,10000次commit总耗时0.52s , 0.68+0.52+2.69=3.89s ,此外还有少量的递归SQL耗时也算在这个4.0s里。
2、 在以上例子中看到, 对于 PL/SQL匿名块、update、commit而言 有execute 阶段 ,而没有 fetch阶段,fetch的次数为0。 对于SELECT语句而言 ,有execute阶段,但是execute阶段的disk、query、current一般为零,统统算在Fetch阶段。
begin for i in 1..10000 loop update fullscan set owner=‘MACLEAN‘ where object_id=i; commit; end loop; end; call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 0 0 0 0 Execute 1 0.62 0.68 178 20037 0 1 Fetch 0 0.00 0.00 0 0 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 2 0.62 0.68 178 20037 0 1 Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: SYS Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ log file sync 1 0.00 0.00 SQL*Net message to client 1 0.00 0.00 PARSING IN CURSOR #5 len=106 dep=0 uid=0 oct=47 lid=0 tim=1345130672819492 hv=3631473533 ad=‘a750b960‘ begin for i in 1..10000 loop update fullscan set owner=‘MACLEAN‘ where object_id=i; commit; end loop; end; END OF STMT PARSE #5:c=1000,e=891,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=1345130672819487 BINDS #5: EXEC #5:c=3968396,e=3907489,p=178,cr=20037,cu=28928,mis=0,r=1,dep=0,og=1,tim=1345130676727033 WAIT #5: nam=‘log file sync‘ ela= 162 buffer#=8084 sync scn=14950441 p3=0 obj#=96606 tim=1345130676727293 WAIT #5: nam=‘SQL*Net message to client‘ ela= 5 driver id=1650815232 #bytes=1 p3=0 obj#=96606 tim=1345130676727343 *** 2013-08-25 03:00:52.748 WAIT #5: nam=‘SQL*Net message from client‘ ela= 234159641 driver id=1650815232 #bytes=1 p3=0 obj#=96606 tim=1345130910887016
3、实际在10046 中真实反映了 上述匿名块的执行时间为 3907489 μs = 3.9s 以及其总的cr=20037 cu=28928( update的19364+commit的9564),但在TKPROF中 匿名块等PL/SQL对象显示的信息并不全面,这可能是为了避免用户的误解。
TKPROF提供了多种排序的方法
Sort options: default
********************************************************************************
count = number of times OCI procedure was executed
cpu = cpu time in seconds executing
elapsed = elapsed time in seconds executing
disk = number of physical reads of buffers from disk
query = number of buffers gotten for consistent read
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call
一般我们对于查询的调优 常用的组合是 SYS=NO fchela, fchela即按照fetch阶段的elapsed time按照从大到小排列
[[email protected] udump]$ tkprof g10r25_ora_30731.trc 30731.tkf sys=no sort=fchela TKPROF: Release 10.2.0.5.0 - Production on Sun Aug 25 03:39:46 2013 Copyright (c) 1982, 2007, Oracle. All rights reserved. Sort options: fchela ******************************************************************************** count = number of times OCI procedure was executed cpu = cpu time in seconds executing elapsed = elapsed time in seconds executing disk = number of physical reads of buffers from disk query = number of buffers gotten for consistent read current = number of buffers gotten in current mode (usually for update) rows = number of rows processed by the fetch or execute call ******************************************************************************** select count(*) from fullscan call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 0 0 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 2 0.01 0.01 1140 1144 0 1 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 4 0.01 0.01 1140 1144 0 1 Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: 64 Rows Row Source Operation ------- --------------------------------------------------- 1 SORT AGGREGATE (cr=1144 pr=1140 pw=0 time=14476 us) 77270 TABLE ACCESS FULL FULLSCAN (cr=1144 pr=1140 pw=0 time=386457 us)
如上Sort options: fchela 后,trace中信息按照fetch elapsed time从长到短排列。
执行计划
Rows Row Source Operation ------- --------------------------------------------------- 1 SORT AGGREGATE (cr=1144 pr=1140 pw=0 time=14476 us) 77270 TABLE ACCESS FULL FULLSCAN (cr=1144 pr=1140 pw=0 time=386457 us)
TKPROF中的执行计划并不现实card、cost等CBO指标, 其所提供的每一个步骤的Rows 、CR、PR 信息对于诊断执行计划到底慢在哪一步有一定帮助, 但是其time耗时信息并不准确。
等待事件
Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 2 0.00 0.00 db file sequential read 1 0.00 0.00 db file scattered read 81 0.00 0.00 SQL*Net message from client 2 0.00 0.00
TKPROF中简要描述了 语句相关的等待事件, 包括遇到了 多少次该等待事件(Times Waited)、 最长的等待是多久 Max.Wait, 总的等待时间Total Waited ,单位均为 S。
10046 中的等待时间描述过于简单,仅为让阅读者简要把握等待问题, 针对等待时间的调优 强烈建议 基于AWR中的wait histogram和ASH去分析, 与他们对比TKPROF显然已经过时了。
示例解析
select count(1) from big1 where object_id between 10 and 100000 and data_object_id between 1 and 1000 and status like ‘VALI%‘ and object_type IN (‘TABLE‘, ‘INDEX‘) call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 20.02 (c) 20.12 (b) 0 1 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 2 1.13 1.33 0 9087 0 1 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 4 21.15 21.45 (a) 0 9088 0 1 Misses in library cache during parse: 1 <== 说明是硬解析 Optimizer mode: ALL_ROWS Parsing user id: 54
- (a)说明该语句总耗时 21.45s
- (b) 说明该语句花在解析上的耗时20.12s
- (c) 说明该语句花在解析上的CPU时间为20.02s
- 语句解析等待时间= 语句解析耗时 – 语句解析CPU耗时 = 20.12 – 20.02 = 0.10 s
以上分析说明 该语句运行的绝大多数耗时花费在解析上, 而解析时 大多数时间是CPU运算, 一般有几种可能导致这么多的CPU运算:
- 语句过于复杂,导致parse解析和optimize优化 消耗较多CPU
- 主机CPU忙,进程分配不到足够的CPU时间片
- 可能遇到resource manager 限制实现CPU
视乎实际情况,需要具体分析。
FILED UNDER: ORACLE, ORACLE基础概念CONCEPT TAGGED WITH: TKPROF
【11g新特性】sec_max_failed_login_attempts
2013/08/23 BY MACLEAN LIU 暂无评论
【11g新特性】sec_max_failed_login_attempts (默认为10,范围为1到unlimited)这个参数以11g 新特性形式引入, 文档对它的描述是
SEC_MAX_FAILED_LOGIN_ATTEMPTS
specifies the number of authentication attempts that can be made by a client on a connection to the server process. After the specified number of failure attempts, the connection will be automatically dropped by the server process.
但是有同学怎么测试都无法生效, 实际该参数只对使用了OCI 的特定程序生效,而使用SQLPLUS是无法生效的, 坑爹的新特性:
SEC_MAX_FAILED_LOGIN_ATTEMPTS only works application uses OCI Program.SEC_MAX_FAILED_LOGIN_ATTEMPTS not work in sqlplus.
OCI Program have the following ,it wil work.
1.You need to use OCI_THREADED mode.
2.You need to set the attribute ofserver, username, password attributes in the appropriate handles:
3.You need to useOCISessionBegin to connect to the database
FILED UNDER: ORACLE, ORACLE 11G新特性
Maclean教你读Oracle 10046 SQL TRACE
2013/08/22 BY MACLEAN LIU 6条评论
有同学一直向Maclean反应希望做一期10046 SQL trace的教程, 正好这几天有空 我们就理一理。
为什么我们要使用10046 trace?
10046 trace帮助我们解析 一条/多条SQL、PL/SQL语句的运行状态 ,这些状态包括 :Parse/Fetch/Execute三个阶段中遇到的等待事件、消耗的物理和逻辑读、CPU时间、执行计划等等。
即10046 为我们揭示了 一条/多条SQL 的运行情况, 对于 以点入手的 SQL调优是很好的辅助工具,特别是在 10g之前没有ASH的情况下。 但整体系统调优 不是10046 所擅长的, 10046 是 性能调优的起钉器 , AWR是性能调优 的锤子。
10046还能帮助我们分析 一些 DDL维护命令的内部工作原理, RMAN、Data Pump Expdp/Impdp等工具的缓慢问题等, 是研究 oracle 数据库原理的 居家旅行必备良品。
10046 和SQL TRACE的区别?
10046 比 SQL_TRACE参数提供更多的控制选项, 更详细的内容输出, 一般Maclean只用10046 而不用sql_trace
10046 和10053 的区别?
10053 是最常用的Oracle 优化器optimizer 跟踪trace, 10053 可以作为我们解析 优化器为什么选择某个执行计划,其中的理由的辅助工具,但并不告诉我们这个执行计划 到底运行地如何。
而10046 并不解释 optimizer优化器的工作, 但它同样说明了在SQL解析parse阶段所遇到的等待事件和所消耗的CPU等资源,以及Execute执行和Fetch阶段的各项指标。
简而言之10046 告诉我们SQL(执行计划)运行地如何, 10053告诉我们 优化器为什么为这个SQL选择某个执行计划。
10046 TRACE的LEVEL:
不同的Level 对应不同的跟踪级别
- 1 启用标准的SQL_TRACE功能 ( 默认) 包含了 SQL语句、响应时间、服务时间、处理的行数,物理读和写的数目、执行计划以及其他一些额外信息。 到版本10.2中 执行计划写入到 trace 的条件是仅当相关游标 已经关闭时, 且与之相关的执行统计信息是所有执行次数的总和数据。 到版本11.1中仅在每次游标的第一次执行后将执行计划写入到trace , 执行统计信息仅仅和这第一次执行相关
- 4 比level 1时多出 绑定变量的 trace
- 8 比level 1多出等待事件,特别对于9i中指出 latch free等待事件很有用,对于分析全表扫描和索引扫描也很有用
- 12 比level 1 多出 绑定变量和 等待事件
- 16 在11g中为每一次执行生成STAT信息,仅在11.1之后可用
- 32 比level 1少执行计划
- 64 和level 1 相比 在第一次执行后还可能生成执行计划信息 ; 条件是某个游标在前一次执行的前提下 运行耗时变长了一分钟。仅在 11.2.0.2中可用
- Level 28 (4 + 8 + 16) 代表 同时启用 level 4 、level 8、level 16
- level 68 ( 64 + 4 ) 代表 同时启用 level 64、level 4
设置的方法如下:
session 级别: alter session set events ‘10046 trace name context forever,level X’;
system 级别 : alter system set events ‘10046 trace name context forever,level X’;
针对非本会话的 某一个进程设置,如果你知道他的SPID 操作系统进程号
oradebug setospid SPID;
oradebug event 10046 trace name context forever, level X;
例如:
[[email protected] ~]$ ps -ef|grep LOCAL oracle 12421 12420 0 Aug21 ? 00:00:00 oracleG10R25 (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq))) oracle 12522 12521 0 Aug21 ? 00:00:00 oracleG10R25 (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq))) oracle 12533 1 0 Aug21 ? 00:00:00 oracleG10R25 (LOCAL=NO) oracle 15354 15353 0 Aug21 ? 00:00:08 oracleG10R25 (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq))) oracle 15419 15418 0 Aug21 ? 00:00:11 oracleG10R25 (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq))) oracle 16219 16218 0 Aug21 ? 00:00:00 oracleG10R25 (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq))) oracle 17098 17097 0 03:12 ? 00:00:00 oracleG10R25 (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq))) 要跟踪 17098 这个进程 SQL> oradebug event 10046 trace name context forever, level 28; Statement processed. 从 sid 定位到 SPID 或者 ORAPID 的 查询如下: SQL> select distinct sid from v$mystat; SID ---------- 141 SQL> select spid,pid from v$Process where addr=(select paddr from v$session where sid=141); SPID PID ------------ ---------- 17196 24 select spid,pid from v$Process where addr=(select paddr from v$session where sid=&SID) 如果只知道 ORA的PID 那么也可以 oradebug setorapid 24; oradebug event 10046 trace name context forever, level 28;
10046 trace 示例解析
这里我们引入一个全表扫描的10046例子 并解析该例子中的TRACE信息:
PARSING IN CURSOR #20 len=44 dep=0 uid=0 oct=3 lid=0 tim=1344883874047619 hv=2241892608 ad=‘a7902a08‘ select count(*) from fullscan where owner=:v END OF STMT PARSE #20:c=2000,e=1087,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=1344883874047610 PARSING IN CURSOR #26 len=198 dep=1 uid=0 oct=3 lid=0 tim=1344883874048534 hv=4125641360 ad=‘a7ab9fc0‘ select obj#,type#,ctime,mtime,stime,status,dataobj#,flags,oid$, spare1, spare2 from obj$ where owner#=:1 and name=:2 and namespace=:3 and remoteowner is null and linkna me is null and subname is null END OF STMT PARSE #26:c=0,e=531,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,tim=1344883874048501 BINDS #26: kkscoacd Bind#0 oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00 oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0 kxsbbbfp=7f9ccfec6bd8 bln=22 avl=01 flg=05 value=0 Bind#1 oacdty=01 mxl=32(08) mxlc=00 mal=00 scl=00 pre=00 oacflg=18 fl2=0001 frm=01 csi=873 siz=32 off=0 kxsbbbfp=7f9ccfec6ba0 bln=32 avl=08 flg=05 value="FULLSCAN" askmaclean.com Bind#2 oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00 oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0 kxsbbbfp=7f9ccfec6b70 bln=24 avl=02 flg=05 value=1 EXEC #26:c=1998,e=1506,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,tim=1344883874050177 WAIT #26: nam=‘db file sequential read‘ ela= 26 file#=1 block#=58007 blocks=1 obj#=37 tim=1344883874050345 WAIT #26: nam=‘db file sequential read‘ ela= 19 file#=1 block#=58966 blocks=1 obj#=18 tim=1344883874050452 PARSING IN CURSOR #25 len=493 dep=1 uid=0 oct=3 lid=0 tim=1344883874051980 hv=2584065658 ad=‘a7a9ef68‘ select t.ts#,t.file#,t.block#,nvl(t.bobj#,0),nvl(t.tab#,0),t.intcols,nvl(t.clucols,0),t.audit$,t.flags,t.pctfree$,t.pctused$,t.initrans,t.maxtrans,t.rowcnt,t.blkcnt,t.e mpcnt,t.avgspc,t.chncnt,t.avgrln,t.analyzetime,t.samplesize,t.cols,t.property,nvl(t.degree,1),nvl(t.instances,1),t.avgspc_flb,t.flbcnt,t.kernelcols,nvl(t.trigflag, 0),n vl(t.spare1,0),nvl(t.spare2,0),t.spare4,t.spare6,ts.cachedblk,ts.cachehit,ts.logicalread from tab$ t, tab_stats$ ts where t.obj#= :1 and t.obj# = ts.obj# (+) END OF STMT PARSE #25:c=1000,e=585,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,tim=1344883874051971 BINDS #25: kkscoacd Bind#0 oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00 oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0 kxsbbbfp=7f9ccfec6bd8 bln=22 avl=04 flg=05 value=96551 EXEC #25:c=3000,e=2757,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,tim=1344883874054930 WAIT #25: nam=‘db file sequential read‘ ela= 21 file#=1 block#=48756 blocks=1 obj#=3 tim=1344883874055059 WAIT #25: nam=‘db file sequential read‘ ela= 18 file#=1 block#=51327 blocks=1 obj#=4 tim=1344883874055149 FETCH #25:c=0,e=538,p=2,cr=5,cu=0,mis=0,r=1,dep=1,og=4,tim=1344883874055512 STAT #25 id=1 cnt=1 pid=0 pos=1 obj=0 op=‘MERGE JOIN OUTER (cr=5 pr=2 pw=0 time=565 us)‘ STAT #25 id=2 cnt=1 pid=1 pos=1 obj=4 op=‘TABLE ACCESS CLUSTER TAB$ (cr=3 pr=2 pw=0 time=228 us)‘ STAT #25 id=3 cnt=1 pid=2 pos=1 obj=3 op=‘INDEX UNIQUE SCAN I_OBJ# (cr=2 pr=1 pw=0 time=115 us)‘ STAT #25 id=4 cnt=0 pid=1 pos=2 obj=0 op=‘BUFFER SORT (cr=2 pr=0 pw=0 time=251 us)‘ STAT #25 id=5 cnt=0 pid=4 pos=1 obj=709 op=‘TABLE ACCESS BY INDEX ROWID TAB_STATS$ (cr=2 pr=0 pw=0 time=207 us)‘ STAT #25 id=6 cnt=0 pid=5 pos=1 obj=710 op=‘INDEX UNIQUE SCAN I_TAB_STATS$_OBJ# (cr=2 pr=0 pw=0 time=33 us)‘ ................ BINDS #20: kkscoacd Bind#0 oacdty=96 mxl=2000(150) mxlc=00 mal=00 scl=00 pre=00 oacflg=03 fl2=1000000 frm=01 csi=873 siz=2000 off=0 kxsbbbfp=7f9ccfec6420 bln=2000 avl=50 flg=05 value="MACLEAN " EXEC #20:c=20996,e=21249,p=7,cr=19,cu=0,mis=1,r=0,dep=0,og=1,tim=1344883874068951 WAIT #20: nam=‘SQL*Net message to client‘ ela= 6 driver id=1650815232 #bytes=1 p3=0 obj#=36 tim=1344883874069011 WAIT #20: nam=‘db file sequential read‘ ela= 23 file#=1 block#=80385 blocks=1 obj#=96551 tim=1344883874069159 WAIT #20: nam=‘db file scattered read‘ ela= 42 file#=1 block#=80386 blocks=7 obj#=96551 tim=1344883874069383 WAIT #20: nam=‘db file scattered read‘ ela= 41 file#=1 block#=82313 blocks=8 obj#=96551 tim=1344883874069543 WAIT #20: nam=‘db file scattered read‘ ela= 30 file#=1 block#=82321 blocks=8 obj#=96551 tim=1344883874069678 WAIT #20: nam=‘db file scattered read‘ ela= 38 file#=1 block#=82329 blocks=8 obj#=96551 tim=1344883874069949 WAIT #20: nam=‘db file scattered read‘ ela= 848 file#=1 block#=82337 blocks=8 obj#=96551 tim=1344883874070846 WAIT #20: nam=‘db file scattered read‘ ela= 63 file#=1 block#=82345 blocks=8 obj#=96551 tim=1344883874071042 WAIT #20: nam=‘db file scattered read‘ ela= 37 file#=1 block#=92593 blocks=8 obj#=96551 tim=1344883874071190 WAIT #20: nam=‘db file scattered read‘ ela= 73 file#=1 block#=92601 blocks=8 obj#=96551 tim=1344883874071393 FETCH #20:c=18997,e=18234,p=1139,cr=1143,cu=0,mis=0,r=1,dep=0,og=1,tim=1344883874087322 WAIT #20: nam=‘SQL*Net message from client‘ ela= 285 driver id=1650815232 #bytes=1 p3=0 obj#=96551 tim=1344883874087675 FETCH #20:c=0,e=3,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=1344883874087715 WAIT #20: nam=‘SQL*Net message to client‘ ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=96551 tim=1344883874087744 *** 2013-08-22 04:44:59.527 WAIT #20: nam=‘SQL*Net message from client‘ ela= 12169104 driver id=1650815232 #bytes=1 p3=0 obj#=96551 tim=1344883886256887 STAT #20 id=1 cnt=1 pid=0 pos=1 obj=0 op=‘SORT AGGREGATE (cr=1143 pr=1139 pw=0 time=18243 us)‘ STAT #20 id=2 cnt=0 pid=1 pos=1 obj=96551 op=‘TABLE ACCESS FULL FULLSCAN (cr=1143 pr=1139 pw=0 time=18200 us)‘ WAIT #0: nam=‘SQL*Net message to client‘ ela= 8 driver id=1650815232 #bytes=1 p3=0 obj#=96551 tim=1344883886257193 WAIT #0: nam=‘SQL*Net message from client‘ ela= 455225 driver id=1650815232 #bytes=1 p3=0 obj#=96551 tim=1344883886712468 WAIT #0: nam=‘SQL*Net message to client‘ ela= 0 driver id=1650815232 #bytes=1 p3=0 obj#=96551 tim=1344883886712594
PARSING IN CURSOR #20 len=44 dep=0 uid=0 oct=3 lid=0 tim=1344883874047619 hv=2241892608 ad=’a7902a08′
select count(*) from fullscan where owner=:v
END OF STMT
PARSE #20:c=2000,e=1087,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=1344883874047610
PARSING IN CURSOR #20 ,这里的#20是游标号, 这个游标号非常重要, 后面的 FETCH 、WAIT、EXECUTE、PARSE 都通过这个游标号和前面的SQL联系起来。
注意可以看到 在执行PARSING IN CURSOR #20 后 ,PARSE #20之后没有紧跟着 #20游标的运行 ,而是跟了 #25、#26游标的运行情况, 仔细看一下 #25和#26他们是 系统递归的recursive SQL ,这些递归SQL由 用户的SQL触发,一般来说是查一些数据字典基表例如 obj$、tab$等,常规情况下 递归SQL运行消耗的资源和时间都非常少。
LEN=44 指SQL的长度
OCT=3 Oracle command type 指Oracle中命令分类的类型 可以通过 V$SQL.COMMAND_TYPE获得对应关系
11g中提供了 V$SQLCOMMAND 视图可以看到完整的对照列表, http://www.askmaclean.com/archives/vsqlcommand-sql-opcodes-and-names.html
LID=0 权限用户ID Privilege user id.
TIM timestamp 一个时间戳, 在9i之前 这个指标的单位是 1/100 s 即 10ms 。 到9i以后单位为 1/1000000 的microsecond 。 这个时间戳可以用来判断 trace中2个点的时间差。 这个 TIm的值来自于V$TIMER视图,这个视图是Oracle内部计时用的。
DEP=0 代表该SQL的递归深入(recursive depth),因为递归SQL可能再引发下一层的递归SQL, 如果DEP=0则说明不是递归SQL,如果DEP>0则说明是递归SQL。
UID=0 UID即USERID 用以标明是谁在解析这个游标, 如果是0则说明是SYS 用户, 具体 用户名和UID对应可以通过如下查询获得:
select user#,name from user$;
OG=1 OG 代表optimizer_mode ,具体对应关系见下表
- 0 游标不可见 或 优化器环境未合理创建
- 1 – ALL_ROWS
- 2 – FIRST_ROWS
- 3 – RULE
- 4 – CHOOSE
mis=0 该指标说明library cache未发生miss,则本次解析 我们没有需要硬解析 而是采用软解析或者更好的方式。 硬解析在Oracle中成本是很高的。 注意由于在任何阶段包括PARSE/EXECUTE/FETCH阶段都可能发生游标被age out的现象,所以在这些阶段都会打印mis指标。如果mis>0则说明可能发生了硬解析。
HV 代表这个SQL 的hash value , 10g之前没有SQL_ID 时 主要靠HASH VALUE 来定位一个SQL
AD 代表SQLTEXT 的地址 来源于 V$SQLAREA.ADDRESS
err 代表 Oracle错误代码 例如ORA-1555
PARSE 是SQL运行的第一个阶段,解析SQL
EXEC 是SQL运行的第二个阶段,运行已经解析过的语句
FETCH 从游标中 fetch数据行
UNMAP 是当游标使用临时表时,若游标关闭则使用UNMAP释放临时表相关的资源,包括释放锁和释放临时段
C 比较重要的指标,代表本步操作消耗的CPU 时间片; 9i以后单位为microsecond
E Elapsed Time ,代表本步操作消耗的自然时间, 9i以后单位为microsecond
这里存在一个问题例如 在我们的例子中PARSE #20:c=2000,e=1087 CPU_TIME> Elapsed time ;
理论上 应当是 Elapsed Time = CPU TIME + WAIT TIME (等待事件的时间), 但是由于CPU TIME 和Elapsed time使用了不同 的clock时钟计时,所以在 2者都很短,或者 是CPU敏感的操作时 有可能 CPU TIME> Elapsed time。
相关的BUG 有:
- Bug 4161114 : IN V$SQL, CPU_TIME > ELAPSED_TIME
- Bug 7603849 : CPU_TIME > ELAPSED_TIME FOR CERTAIN SQL’S IN V$SQL
- Bug 7580277 : ELAPSED_TIME SHOWING 0 FOR CERTAIN SQL’S IN V$SQL
- Bug 8243074 : INCORRECT ELAPSED_TIME IN V$SQL
该问题可能 在12c中得到修复
p 物理读的数目
CR CR一致性读引起的buffer get 数目
CU 当前读current read 引起的buffer get 数目
r 处理的行数
CLOSE #[CURSOR]:c=%u e=%u dep=%d type=%u tim=%u ==》一个游标关闭的例子
CLOSE 游标关闭
type 关闭游标的操作类型
- 0 该游标从未被缓存且执行次数小于3次,也叫hard close
- 1 该游标从未被缓存但执行次数至少3次,若在session cached cursor中有free slot 则将该游标放入session cached cursor
- 2 该游标从未被缓存但执行次数至少3次,该游标置入session cached cursor的条件是讲老的缓存age out掉
- 3 该游标已经在缓存里,则还会去
STAT #[CURSOR] id=N cnt=0 [pid=0 pos=0 obj=0 op=’SORT AGGREGATE ‘]
- STAT 相关行反应解释执行计划的统计信息
- [CURSOR] 游标号
- id 执行计划的行数 从1开始
- cnt 该数据源的行数
- pid 该数据源的 父ID
- pos 在执行计划中的位置
- obj 对应数据源的 object id
- op= 数据源的访问操作,例如 FULL SCAN
11g 以上还提供如下信息:
STAT #2 id=1 cnt=26 pid=0 pos=1 obj=0 op=’HASH GROUP BY (cr=1143 pr=1139 pw=0 time=61372 us)’
STAT #2 id=2 cnt=77276 pid=1 pos=1 obj=96551 op=’TABLE ACCESS FULL FULLSCAN (cr=1143 pr=1139 pw=0 time=927821 us)’
- CR 代表一致性读的数量
- PR 代表物理读的数量
- pw 代表物理写的数量
- time 单位为microsecond,本步骤的耗时
- cost 本操作的优化器成本
- size 评估的数据源大小,单位为字节
- card 评估的优化器基数Cardinality.
XCTEND rlbk=0, rd_only=1
- XCTEND 一个事务结束的标志
- rlbk 如果是1代表 有回滚操作, 如果是0 代表不会滚 即 commit提交了
- rd_only 如果是1代表 事务只读 , 如果是0 说明数据改变发生过
绑定变量
BINDS #20:
kkscoacd
Bind#0
oacdty=96 mxl=2000(150) mxlc=00 mal=00 scl=00 pre=00
oacflg=03 fl2=1000000 frm=01 csi=873 siz=2000 off=0
kxsbbbfp=7f9ccfec6420 bln=2000 avl=50 flg=05
value=”MACLEAN
- BINDS #20: 说明 绑定变量 是针对 20号游标的
- kkscoacd 是绑定变量相关的描述符
- Bind#0 说明是第0个变量
- oacdty data type 96 是 ANSI fixed char
- oacflg 代表绑定选项的特殊标志位
- size 为该内存chunk分配的内存大小
- mxl 绑定变量的最大长度
- pre precision
- scl Scale
- kxsbbbfp buffer point
- bln bind buffer length
- avl 实际的值的长度
- flg 代表绑定状态
- value=”MACLEAN 实际的绑定值
如果看到 “bind 6: (No oacdef for this bind)”类似的信息则说明在trace时 还没有定义绑定数据。 这可能是在trace时游标还没绑定变量。
WAIT #20: nam=’db file scattered read’ ela= 42 file#=1 block#=80386 blocks=7 obj#=96551 tim=1344883874069383
- WAIT #20 等待 20号游标的相关等待事件
- Nam 等待针对的事件名字,它的P1、P2、P3可以参考视图V$EVENT_NAME,也可以从V$SESSION、ASH中观察到等待事件
- ela 本操作的耗时,单位为microsecond
- p1,p2,p3 针对该事件的三个描述参数,见V$EVENT_NAME
在上例中针对 db file scattered read , P1为文件号, P2为 起始块号, p3为 读的块数, 即db file scattered read 是从 1号文件的第80386 个块开始一次读取了7个块。
注意在10046中 出现的WAIT 行信息 都是 已经结束的等待事件, 而当前等待则不会在trace中出现,直到这个当前等待结束。 你可以通过systemstate dump/errorstack等trace来获得当前等待信息。