使用awr來診斷資料庫效能問題

awr報告是一種極其有效的診斷工具來確定潛在的導致資料庫效能問題的原因.

通常當效能問題被檢查到時你可以在出現效能問題期間收集一個awr報告.收集awr報告的期間最好不要超過一個小時否則有可能會丟失一些細節.

當資料庫效能在可接受期間也可以收集awr報告來作為基線當出現資料庫效能問題是可以用來進行比較.要確保效能基線收集的時間與出現效能問題時收集awr的時間相同這樣才有可比性.

當我們正在查詢效能問題是我們的主要關注點在資料庫正在等待什麼.當程式等待時它們會被阻止做任何操作.

top等待事件提供了對於問題來說需要我們關注的資訊而不用浪費時間去調查其它的原因.

top 5時間事件
注意top等待部分是整個awr報告中的最重要的一個部分它可以用來量化效能和進行診斷比較

Top 5 Timed Events Avg %Total
~~~~~~~~~~~~~~~~~~ wait Call
Event Waits Time (s) (ms) Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
db file scattered read 10,152,564 81,327 8 29.6 User I/O
db file sequential read 10,327,231 75,878 7 27.6 User I/O
CPU time 56,207 20.5
read by other session 4,397,330 33,455 8 12.2 User I/O
PX Deq Credit: send blkd 31,398 26,576 846 9.7 Other
-------------------------------------------------------------

top 5等待部分報告了一系列有用的相關等待事件.它記錄了在遇到效能期間所發生的等待次數和等待總的時間以及每個事件的平均等待時間.

在上面的這個例子中,幾乎60%的等待時間是與IO相關的讀取操作
事件'db file scattered read'是典型用於全表掃描和索引快速完全掃描時執行多塊讀相關的等待事件
事件'db file sequential read'是用於塊讀和通常用於不能執行多塊讀時相關的等待事件(例如索引讀取)

另外的20%的等待時間劃CPU time.高cpu利用率通常是低效能sql(執行昂貴的IO操作)的一個識別符號(或者sql語句有使用更少資源的潛能)

基於以上的資訊我們將會調查這些等待是否指示了效能問題.如果是解決這些問題,如果不是繼續檢視下一部分資訊是否是造成效能問題的原因

有兩個原因讓IO相關的等待事件成為top等待事件
1.資料庫正在執行大量的讀取操作
2.單個讀取操作很慢

top5等待事件有以下幫助:
1.資料庫正在執行大量的讀取操作?
這部分資訊顯示了在這個awr報告期間這些等待事件中每一個執行了1000萬次讀取,這個讀取次數是否是大量讀取操作取決於awr報告的持續時間是1小時還是1分鐘.檢查報告期間來評估這個問題.如果讀取操作過度那麼為什麼資料庫還會執行大量的讀取操作?資料庫只讀取資料是因為執行的sql語句指示它進行讀取操作為了調整可以檢視sql statistics部分的資訊.

2.是不是單個讀取操作慢?
這部分顯示了兩個等待<=8ms的IO相關等待事件,這個是快是慢取於硬體底層的IO子系統,但通常低於20ms是可以接受

如果IO慢,那麼可以從'Tablespace IO stats'部分得到以下資訊:

Tablespace IO Stats DB/Inst: VMWREP/VMWREP Snaps: 1-15
-> 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)
-------------- ------- ------ ------- ------------ -------- ---------- ------
TS_TX_DATA
14,246,367 283 7.6 4.6 145,263,880 2,883 3,844,161 8.3
USER
204,834 4 10.7 1.0 17,849,021 354 15,249 9.8
UNDOTS1
19,725 0 3.0 1.0 10,064,086 200 1,964 4.9
AE_TS
4,287,567 85 5.4 6.7 932 0 465,793 3.7
TEMP
2,022,883 40 0.0 5.8 878,049 17 0 0.0
UNDOTS3
1,310,493 26 4.6 1.0 941,675 19 43 0.0
TS_TX_IDX
1,884,478 37 7.3 1.0 23,695 0 73,703 8.3
SYSAUX
346,094 7 5.6 3.9 112,744 2 0 0.0
SYSTEM
101,771 2 7.9 3.5 25,098 0 653 2.7

特別注意的是檢視RD(ms)的值,如果每次讀取時間的值高於20ms,那麼你可以從作業系統層開始調查IO屏頸.注意:你應該忽略相關的空閒的表空間/檔案當你發現RD(ms)的值較高時可能是因為磁碟的spinup造成的這與效能無關.如果你讀取1000萬次讀取被認為是IO慢這不太可能它可能是表空間/檔案只有10個讀取操作造成的問題

雖然高等待'db file scattered read'和'db file sequential read'事件可能與IO相關,但是實際上發現大部分這些等待事件基於資料庫正在執行的sql語句來說是正常的.實際上,在一個高度最佳化的資料中,希望它們出現在top等待事件中,因此這意味著資料庫沒有效能問題.

它們被用來評估是否高等待說明了某些sql語句沒有使用最佳的訪問路徑.如果有大量的'db file scattered read'等待事件,那麼sql可能沒有使用最佳的訪問路徑因此使用了全表掃描而不是索引掃描(或者可能是丟失索引或者沒有最佳的索引可用).此外,大量的'db file sequential read'等待事件可以說明了sql語句正在使用非選擇性索引且因此要讀取更多的索引塊或者使用了錯誤的索引.因此這些等待事件可能說明sql語句執行計劃效能較低.

不管怎樣,都應該從awr報告中檢查top資源消耗的情況來判斷它們是否過度或是否可以改進

注意上面有20%的等待時間是cpu時間.在檢視sql統計時也應該被檢查.後面的檢查是依據tops等待進行的.例如在上面的top5等待事件中前功盡棄3個是指示有效能不佳的sql語句應該進行調查

同樣的如果你沒有看到latch等待那麼latch就不是造成效能問題的原因所以就不需要繼續調查latch等待.

一般來說,如果資料庫慢那麼top5等待事件中包含"cpu"和"db file sequential read"和"db file scattered read"那麼這說明將要注意檢視top sql(透過邏輯和物理讀取分類的)部分和叫做sql調整指導(或手動調整它們)來確保
它們有效的執行.

SQL Statistics
SQL ordered by Elapsed Time
SQL ordered by CPU Time
SQL ordered by User I/O Wait Time
SQL ordered by Gets
SQL ordered by Reads
SQL ordered by Physical Reads(UnOptimized)
SQL ordered by Executions
SQL ordered by Parse Calls
SQL ordered by Sharable Memory
SQL ordered by Version Count
SQL ordered by Cluster Wait Time
Complete List of SQL Text
上面不同的sql統計資訊應該根據top5等待事件中的不同等待事件進行檢視.例如在我們的例子中,我們看到有'db file scattered read','db file sequential read'和cpu.對於這些我們要重點關注SQL ordered by CPU Time,SQL ordered by Gets和SQL ordered by Reads部分.

通常檢視'SQL ordered by gets'部分指示sql語句有較高的快取獲取通常需要進行合適的調優:

SQL ordered by Gets
-> Resources reported for PL/SQL code includes the resources used by all SQL
statements called by the code.
-> Total Buffer Gets: 4,745,943,815
-> Captured SQL account for 122.2% of Total

Gets CPU Elapsed
Buffer Gets Executions per Exec %Total Time (s) Time (s) SQL Id
-------------- ------------ ------------ ------ -------- --------- -------------
1,228,753,877 168 7,314,011.2 25.9 8022.46 8404.73 5t1y1nvmwp2
SELECT ADDRESSID",CURRENT$."ADDRESSTYPEID",CURRENT$URRENT$."ADDRESS3",
CURRENT$."CITY",CURRENT$."ZIP",CURRENT$."STATE",CURRENT$."PHONECOUNTRYCODE",
CURRENT$."PHONENUMBER",CURRENT$."PHONEEXTENSION",CURRENT$."FAXCOU

1,039,875,759 62,959,363 16.5 21.9 5320.27 5618.96 grr4mg7ms81
Module: DBMS_SCHEDULER
INSERT INTO "ADDRESS_RDONLY" ("ADDRESSID","ADDRESSTYPEID","CUSTOMERID","
ADDRESS1","ADDRESS2","ADDRESS3","CITY","ZIP","STATE","PHONECOUNTRYCODE","PHONENU

854,035,223 168 5,083,543.0 18.0 5713.50 7458.95 4at7cbx8hnz
SELECT "CUSTOMERID",CURRENT$."ISACTIVE",CURRENT$."FIRSTNAME",CURRENT$."LASTNAME",CU<
RRENT$."ORGANIZATION",CURRENT$."DATEREGISTERED",CURRENT$."CUSTOMERSTATUSID",CURR
ENT$."LASTMODIFIEDDATE",CURRENT$."SOURCE",CURRENT$."EMPLOYEEDEPT",CURRENT$.

調整可以手動進行也可以透過sql調整指導來進行

對上面的資訊進行分析:
Total Buffer Gets: 4,745,943,815
我們假設這是一個時間間隔為1小時的awr報告,這是對於buffer get來說是一個重要的數字因此這證實了為了確保它們正使用最佳的訪問路麼它們是值得調查的top sql語句.

單個 buffer gets
對於單個語句的buffer gets是非常高得最小的也有854,035,223次.這三個語句實際上指出了有大量buffer gets的兩大原因:
過度的buffer gets/exectuion sql_id '5t1y1nvmwp2'和'4at7cbx8hnz'僅僅只執行了168次,但每一次執行讀取超過500萬的buffer.這個語句是要被進行調優的主要物件因為buffer在太高了.

過度的執行
另一方面sql_id 'grr4mg7ms81'每次執行只讀取16個buffer.調整這個語句不能有效的減少buffer 讀.然而這個問題可能是由這個語句的執行次數造成的---執行62,959,363次.改變這個語句的呼叫方式--它很可能在一個迴圈中一次獲取一行記錄,可以修改成一次執行獲取多條記錄那麼這樣就會有效的減少buffer讀取.

記住這些數字對於繁忙的工作環境可能是正常的.可通透過使用這個時間的awr報告與效能基線awr報告進行比較,你可以看看這些語句在資料庫效能良好的情況下是不是也執行了這麼多的buffer讀取.如果也是那麼就不用關注這個問題了可以忽略它們(因為改進這些語句可以提高一些效能)

其它的sql統計資訊部分
在sql統計資訊部分有不同的報告部分用於指示不同的原因,如果你沒有特定問題那麼檢視這部分資訊的作用有限.
Waits for 'Cursor: mutex/pin'
如果在這有mutex等待象"Cursor:pin S wait on X' or 'Cursor:mutex X',這些象徵著解析問題.
最基本的就是檢視有高解析次數'SQL ordered by Parse Cllas' 或高版本次數的sql語句 'SQL ordered by Version Count'
這是最有可能造成問題的原因.

Load Profile 負載概要
根據等待事件,負載概要部分也提供有用的後臺資訊或與問題相關的特定資訊

Load Profile
~~~~~~~~~~~~ Per Second Per Transaction
--------------- ---------------
Redo size: 4,585,414.80 3,165,883.14
Logical reads: 94,185.63 65,028.07
Block changes: 40,028.57 27,636.71
Physical reads: 2,206.12 1,523.16
Physical writes: 3,939.97 2,720.25
User calls: 50.08 34.58
Parses: 26.96 18.61
Hard parses: 1.49 1.03
Sorts: 18.36 12.68
Logons: 0.13 0.09
Executes: 4,925.89 3,400.96
Transactions: 1.45

% Blocks changed per Read: 42.50 Recursive Call %: 99.19
Rollback per transaction %: 59.69 Rows per Sort: 1922.64

在這個例子中,等待事件部分顯示的問題是sql語句執行的問題所以負載概要也能檢查出相關的資訊.

如果你正在為了通常的調整在看awr報告,你可以檢視負載部分來顯示相關的有高物理寫的高重做活動.在上面的資訊中寫與讀的負載比值高達到了43.50%.

此外這裡硬解析與軟解析比較低.如果在top等待事件中有'library cache:mutex X',那麼整個解析率的統計資訊與這些等待事件息息相關

與效能基線awr報告進行比較將提供最好的資訊,例如,可以透過比較重做的大小,使用者的呼叫和解析來看負載的改變

Instance Efficiency例項的效率
例項的效率統計資訊對於通常的調整來定位特定的問題是很有用的(除非等待事件已經指示出問題的原因)

Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Buffer Nowait %: 99.91 Redo NoWait %: 100.00
Buffer Hit %: 98.14 In-memory Sort %: 99.98
Library Hit %: 99.91 Soft Parse %: 94.48
Execute to Parse %: 99.45 Latch Hit %: 99.97
Parse CPU to Parse Elapsd %: 71.23 % Non-Parse CPU: 99.00

在上面的這個例子中這部分最重要的統計資訊是"% Non-Parse CPU",因為這指示了在top等待事件中幾乎所有的CPU時間
都花在了執行操作上而不是解析操作,這意味著調整sql可能提高效能.

如果我們正在調整,那麼94.48%的軟解析率顯示了硬解析率是較小的.這麼高的解析率說明很好的使用了共享遊標.通常我們希望這個統計值接近100%,但記住有一小部分的百分比不是依賴於應用程式的.例如在一個資料倉儲環境中,硬解析可能由於使用了物化檢視或直方圖變得比較高.所以在出現效能問題時與效能基線awr報告進行比較是很重要的.

Latch Activity 閂鎖活動
在這個例子中我們不能看到有效的閂鎖等待可以忽略此部分資訊.然而,如果閂鎖等待很嚴重那麼我們將基於

Latch Sleep Breakdown來檢視閂鎖等待相關的資訊
Latch Sleep Breakdown

* ordered by misses desc

Latch Name
----------------------------------------
Get Requests Misses Sleeps Spin Gets Sleep1 Sleep2 Sleep3
-------------- ----------- ----------- ---------- -------- -------- --------
cache buffers chains
2,881,936,948 3,070,271 41,336 3,031,456 0 0 0
row cache objects
941,375,571 1,215,395 852 1,214,606 0 0 0
object queue header operation
763,607,977 949,376 30,484 919,782 0 0 0
cache buffers lru chain
376,874,990 705,162 3,192 702,090 0 0 0

這裡的頂級閂鎖是cache buffers chains,cache buffers chains閂鎖是用來保護從磁碟讀取到緩衝區快取中的資料.當看到資料正在被讀取時這是很正常的閂鎖.當這個出現壓力時閂鎖sleeps資料就會趨向於這些查詢請求的等待次數這些競爭可能是由於低效的sql讀取相同的buffer造成的.

在上面的例子中雖然buffer gets中的get請求的次數是2,881,936,948但sleeps次數是41,336是較低的.sleeps與misses的平均比率(avg slps/miss)是較低的.原因是伺服器能夠處理這樣規模的資料因此這裡對於cache buffers chains閂鎖來說沒有什麼競爭.

cpu等待事件
僅僅因為cpu等待出現在awr報告中的top等待事件中不能說明什麼問題.然而如果效能慢且cpu使用率高那麼可以調查cpu等待事件,首先可以檢查awr報告中的消耗cpu較多的sql語句
SQL ordered by CPU Time
-> Resources reported for PL/SQL code includes the resources used by all SQL
statements called by the code.
-> % Total is the CPU Time divided into the Total CPU Time times 100
-> Total CPU Time (s): 56,207
-> Captured SQL account for 114.6% of Total

CPU Elapsed CPU per % Total
Time (s) Time (s) Executions Exec (s) % Total DB Time SQL Id
---------- ---------- ------------ ----------- ------- ------- -------------
20,349 24,884 168 121.12 36.2 9.1 7bbhgqykv3cm9
Module: DBMS_SCHEDULER
DECLARE job BINARY_INTEGER := :job; next_date TIMESTAMP WITH TIME ZONE := :myda
te; broken BOOLEAN := FALSE; job_name VARCHAR2(30) := :job_name; job_subname
VARCHAR2(30) := :job_subname; job_owner VARCHAR2(30) := :job_owner; job_start
TIMESTAMP WITH TIME ZONE := :job_start; job_scheduled_start TIMESTAMP WITH TIME

總的cpu時間:56,207,大概為15分鐘.這個資訊是否有效依據報告的持續的時間週期.消耗cpu的頂級sql使用了20,349秒大約5分鐘佔整個資料庫時間的9.1%.執行了168次.