AWR報告分析之一：高 DB CPU 消耗的效能根源-eygle

dawn009發表於2014-08-06

準備寫一個系列，跟進一些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 JDBC Thin Client select * from ( select row_.*,...
554,429,813 42,299 13,107.40 23.22 9,923.23 40.9 0 JDBC Thin Client select * from ( select row_.*,...
503,809,511 127,506 3,951.26 21.10 7,669.52 37.3 0 JDBC Thin Client select * from (select JOBID, S...
30,497,069 2,331 13,083.26 1.28 409.63 42.2 0 JDBC Thin Client select * from ( select trunc(P...
24,457,802 1,607 15,219.54 1.02 208.90 45.4 0 JDBC Thin Client select this_.PID as PID10_0_, ...
10,935,241 3,791 2,884.53 0.46 462.83 40.4 0 JDBC Thin Client select * from (select JOBID, S...
8,294,720 799 10,381.38 0.35 73.10 40.1 0 JDBC Thin Client select * from ( select row_.*,...
8,090,724 581 13,925.51 0.34 209.79 43.3 0 JDBC Thin Client select * from ( select trunc(P...
4,568,220 123 37,140.00 0.19 19.83 37.9 0 JDBC Thin Client select * from ( select rownum ...
4,151,731 316 13,138.39 0.17 28.95 37.8 0 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報告參考連結：

來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/29119536/viewspace-1246347/，如需轉載，請註明出處，否則將追究法律責任。

相關文章