« EMD_MAINTENANCE 定时任务引起的资源消耗 | Blog首页 | 嘉年华回眸:商圈网CTO丁晓强-复杂系统的运维平衡之道 »
AWR报告分析之一:高 DB CPU 消耗的性能根源
作者:eygle | 【转载请注出处】|【云和恩墨 领先的zData数据库一体机 | zCloud PaaS云管平台 | SQM SQL审核平台 | ZDBM 数据库备份一体机】
链接:https://www.eygle.com/archives/2012/11/awr_db_cpu_high_sample.html
链接:https://www.eygle.com/archives/2012/11/awr_db_cpu_high_sample.html
准备写一个系列,跟进一些AWR报告,做一些简单分析,从中表达一些思路和想法,这些AWR报告可能来自公众发布,在这里予以引用。
以下这份AWR报告的TOP 5 Event可以看出,其CPU消耗超高,占 42.59% 的事件比例,而Log File Sync单次等待达到12毫秒,这表明IO可能存在迟缓:
Event | Waits | Time(s) | Avg wait (ms) | % DB time | Wait Class |
---|---|---|---|---|---|
DB CPU | 22,574 | 42.59 | |||
log file sync | 25,313 | 310 | 12 | 0.58 | Commit |
db file sequential read | 10,645 | 24 | 2 | 0.05 | User I/O |
direct path read | 9,191 | 22 | 2 | 0.04 | User I/O |
enq: TX - row lock contention | 11 | 5 | 455 | 0.01 | Application |
这个报告来自60分钟的数据库采样:
Snap Id | Snap Time | Sessions | Cursors/Session | |
---|---|---|---|---|
Begin Snap: | 6603 | 19-Nov-12 08:00:15 | 261 | 2.2 |
End Snap: | 6604 | 19-Nov-12 09:00:20 | 260 | 3.0 |
Elapsed: | 60.09 (mins) | |||
DB Time: | 883.34 (mins) |
关注一下负载概要信息,数据库每秒仅仅折合4.8个事务,而此前的LOG File Sync等待较高,这说明IO资源可能被其他操作占用,事务之外,就是查询,也就是说,可能有大量低效查询消耗尽了IO资源:
Per Second | Per Transaction | Per Exec | Per Call | |
---|---|---|---|---|
DB Time(s): | 14.7 | 3.0 | 0.07 | 0.02 |
DB CPU(s): | 6.3 | 1.3 | 0.03 | 0.01 |
Redo size: | 55,291.8 | 11,421.6 | ||
Logical reads: | 662,383.2 | 136,828.5 | ||
Block changes: | 189.9 | 39.2 | ||
Physical reads: | 7.0 | 1.5 | ||
Physical writes: | 19.9 | 4.1 | ||
User calls: | 883.5 | 182.5 | ||
Parses: | 21.1 | 4.4 | ||
Hard parses: | 3.4 | 0.7 | ||
W/A MB processed: | 1,170.6 | 241.8 | ||
Logons: | 1.2 | 0.3 | ||
Executes: | 214.9 | 44.4 | ||
Rollbacks: | 0.0 | 0.0 | ||
Transactions: | 4.8 |
通过SQL的SQL逻辑读部分,可以发现导致异常的SQL查询,前两个SQL供占72.27的逻辑读,显然是这两条SQL消耗了IO资源:
Buffer Gets | Executions | Gets per Exec | %Total | Elapsed Time (s) | %CPU | %IO | SQL Id | SQL Module | SQL Text |
---|---|---|---|---|---|---|---|---|---|
1,171,388,996 | 90,764 | 12,905.88 | 49.05 | 30,514.20 | 44.7 | 0 | 08v35uwaj38aa | JDBC Thin Client | select * from ( select row_.*,... |
554,429,813 | 42,299 | 13,107.40 | 23.22 | 9,923.23 | 40.9 | 0 | btn84j9rhuf4h | JDBC Thin Client | select * from ( select row_.*,... |
503,809,511 | 127,506 | 3,951.26 | 21.10 | 7,669.52 | 37.3 | 0 | cp9wdanzmzj4q | JDBC Thin Client | select * from (select JOBID, S... |
30,497,069 | 2,331 | 13,083.26 | 1.28 | 409.63 | 42.2 | 0 | fqjyuzjgm89qv | JDBC Thin Client | select * from ( select trunc(P... |
24,457,802 | 1,607 | 15,219.54 | 1.02 | 208.90 | 45.4 | 0 | 8tptxzh309raz | JDBC Thin Client | select this_.PID as PID10_0_, ... |
10,935,241 | 3,791 | 2,884.53 | 0.46 | 462.83 | 40.4 | 0 | 9dpwkhfwnqfqa | JDBC Thin Client | select * from (select JOBID, S... |
8,294,720 | 799 | 10,381.38 | 0.35 | 73.10 | 40.1 | 0 | 0nn3rt489dkqz | JDBC Thin Client | select * from ( select row_.*,... |
8,090,724 | 581 | 13,925.51 | 0.34 | 209.79 | 43.3 | 0 | 5902s014jdg6n | JDBC Thin Client | select * from ( select trunc(P... |
4,568,220 | 123 | 37,140.00 | 0.19 | 19.83 | 37.9 | 0 | 55u237k35a317 | JDBC Thin Client | select * from ( select rownum ... |
4,151,731 | 316 | 13,138.39 | 0.17 | 28.95 | 37.8 | 0 | d1515xp5t2xtw | JDBC Thin Client | select * from (select JOBID, S... |
在"Segments by Logical Reads"部分可以看到,逻辑读集中在一个对象上,第一位的表分区占用89.86%的逻辑读:
Owner | Tablespace Name | Object Name | Subobject Name | Obj. Type | Logical Reads | %Total |
---|---|---|---|---|---|---|
NCSS | NCSSJOBSITE00 | STU_SEARCHJOB | SITE00 | TABLE PARTITION | 2,145,895,024 | 89.86 |
STPSUSER | STPS2 | TEACHER_INFO | TABLE | 35,438,144 | 1.48 | |
NCSS | NCSS_INDEX | STU_SEARCHJOB_PK | INDEX | 18,438,384 | 0.77 | |
NCSS | NCSSJOBSITE0000 | STU_SEARCHJOB | SITE2101 | TABLE PARTITION | 17,049,488 | 0.71 |
NCSS | NCSS | STU_BASICINFO | TABLE | 5,766,448 | 0.24 |
接下来如果考察SQL,观察其执行计划,就应该能够发现,可能是索引缺失导致了全表或全分区的扫描。
AWR报告参考链接:
http://www.eygle.com/pdf/awrrpt_1_6603_6604.html
历史上的今天...
>> 2011-11-22文章:
>> 2009-11-22文章:
>> 2008-11-22文章:
>> 2006-11-22文章:
>> 2005-11-22文章:
By eygle on 2012-11-22 17:06 | Comments (0) | Case | 3058 |