awr效能問題排查第一篇

對於awr，裡面涵蓋的內容比較雜，有時候看報告的時候總是不知道該怎麼下手。時間長了，可能會有一些閱讀習慣或者心得。今天在看大師chris lawson的一篇博文對於awr的一些心得()，還是蠻有收穫，趕緊按照這個方子來細細品味一番。
首先是檢視等待事件，這個也是老規矩。
不過先把db time先附上，更有針對性。
這是一個10分鐘的awr報告，基於Linux平臺，11gR2 64位。

	Snap Id	Snap Time	Sessions	Cursors/Session
Begin Snap:	17148	31-Oct-14 13:20:02	3397	5.6
End Snap:	17149	31-Oct-14 13:30:03	3471	5.7
Elapsed:		10.01 (mins)
DB Time:		262.49 (mins)

Top 5 Timed Foreground Events

Event	Waits	Time(s)	Avg wait (ms)	% DB time	Wait Class
db file sequential read	7,138,268	9,948	1	63.16	User I/O
DB CPU		4,405		27.97
direct path read	104,507	903	9	5.73	User I/O
db file parallel read	103,319	336	3	2.13	User I/O
log file sync	49,187	282	6	1.79	Commit

-->檢視sequential read指標
這個指標很實用，可以在不同的平臺間進行比較,但是scattered read這種指標就不好比較了。
延遲一般需要在10ms以下,或者至少100 reads/sec，在基於SAN儲存快取資料的情況下，sequential read的指標有時候會保持在2ms左右，這個只能說明SAN已經把資料轉化為快取了，倒不能說明硬碟驅動確實很快。
上面的awr可以看到平均的延遲是在1ms以內，算是正常。

-->檢視top elapsed time sql
這個時候可以根據elapsed time得到一個sql執行情況的概覽。檢視這個的主要目的就是得到執行時間較長的sql語句。按照10分鐘對的一個頻度，executions為0的sql都需要格外注意，同時兼顧所佔的比例。

SQL ordered by Elapsed Time

Elapsed Time (s)	Executions	Elapsed Time per Exec (s)	%Total	%CPU	%IO	SQL Id	SQL Module	SQL Text
1,243.85	29	42.89	7.90	7.32	94.81	cjxrg4qpadvgw	fextract@ccbdbpr1 (TNS V1-V3)	SELECT .
942.47	27	34.91	5.98	7.81	95.75	5y3d011ygwfyx	fextract@ccbdbpr1 (TNS V1-V3)	SELECT
613.45	0		3.90	4.81	97.32	9yn2xdw7uy0bq	JDBC Thin Client	select /*+ index(s SERVICE_
606.64	555	1.09	3.85	94.74	4.89	7yp93zzstn5gh	TB1Manager@ccbdbpr1 (TNS V1-V3)	update (select /*+ index(
602.56	0		3.83	14.57	90.57	0cdthzpx2jn4q	JDBC Thin Client	SELECT
602.53	0		3.83	4.70	97.30	b4c5cvdza03m3	JDBC Thin Client	SELECT
578.66	31	18.67	3.67	11.61	92.22	cc9x1wp2tdgdx	fextract@ccbdbpr1 (TNS V1-V3)	SELECT
547.03	1	547.03	3.47	78.67	17.69	gbqz84d1jggdq	JDBC Thin Client	/* MMO_Memo_getMemoList_1 */ S...
523.83	3	174.61	3.33	29.21	72.21	4gz51fphuarsw	JDBC Thin Client	/*ProcInstScanner_selectAv...
496.38	0		3.15	4.73	96.39	6gvd0gbp58kbc	SQL*Plus	INSERT INTO ..
420.94	6	70.16	2.67	48.53	49.96	00jrngwmz2vxx	JDBC Thin Client	select...

標黃的部分就是參考的依據，可以根據elapsed time和executions來做一個評估。

-->檢視db time
這個部分可以根據time model的部分得到。這個部分能夠得到一個大體的比例，看看db time都主要耗在哪些方面了。

Statistic Name	Time (s)	% of DB Time
sql execute elapsed time	14,854.47	94.32
DB CPU	4,404.99	27.97
parse time elapsed	64.23	0.41
PL/SQL execution elapsed time	36.26	0.23
sequence load elapsed time	24.11	0.15
hard parse elapsed time	8.79	0.06
connection management call elapsed time	7.85	0.05
RMAN cpu time (backup/restore)	7.74	0.05
inbound PL/SQL rpc elapsed time	6.28	0.04
repeated bind elapsed time	0.11	0.00
hard parse (sharing criteria) elapsed time	0.06	0.00
failed parse elapsed time	0.03	0.00
PL/SQL compilation elapsed time	0.01	0.00
DB time	15,749.31
background elapsed time	1,394.65
background cpu time	68.34

-->檢視硬碟讀的消耗部分
透過這個部分可以得到哪些sql正在進行大量的硬碟讀，透過sql order by reads來得到。
經過分析
sql(gbqz84d1jggdq)佔用了22%的硬碟讀，比例是很高的，檢視sql語句發現走的是一個全表掃描，表是億級的大表。
sql(00jrngwmz2vxx)使用union的地方存在問題，導致了全表掃描，細節可以參考http://blog.itpub.net/23718752/viewspace-1209397/  已經做了完整的調優解釋。
sql(4gz51fphuarsw,6fu3z8pqd2y9g)是產品線的兩個通用sql,已經做了最佳化，其中有個大表做了全表掃描加並行，相對了最快的方式了。
sql(98dyqu3xsgyf5)是一個簡單的select 查詢，但是也走了全表掃描，經過排查發現這個大表竟然在最開始規劃的時候丟掉了索引，所以這個問題也是一個比較糾結的錯誤。需要協調解決。

Physical Reads	Executions	Reads per Exec	%Total	Elapsed Time (s)	%CPU	%IO	SQL Id	SQL Module	SQL Text
8,901,984	1	8,901,984.00	22.37	547.03	78.67	17.69	gbqz84d1jggdq	JDBC Thin Client	/* MMO_Memo_getMemoList_1 */ S...
6,712,998	6	1,118,833.00	16.87	420.94	48.53	49.96	00jrngwmz2vxx	JDBC Thin Client	/* AR9_AR9GetPaymentSMS_select...
5,957,336	3	1,985,778.67	14.97	523.83	29.21	72.21	4gz51fphuarsw	JDBC Thin Client	/* CL_ProcInstScanner_selectAv...
4,880,228	3	1,626,742.67	12.26	309.94	18.47	78.67	6fu3z8pqd2y9g	JDBC Thin Client	/* CL_WaitScanner_selectWorkab...
2,015,674	36	55,990.94	5.06	94.81	27.40	70.35	98dyqu3xsgyf5	JDBC Thin Client	/* null_CL9CrdMntrExtract_sele...

-->檢視logical reads
這個部分可以排查出那些執行效率低下的sql語句。
檢視以下的幾個sql,
sql(7yp93zzstn5gh)消耗了大量的邏輯讀,經過檢視，這個sql語句沒有問題，但是表級存在著大量的碎片，一個分割槽表只有幾十條資料，但是blocks卻有幾十萬。
sql(1hg2wcuapy3y3)檢視執行計劃時，發現執行計劃的消耗太高。cost達到近 273K,這條sql語句還是需要好好排查一番。

Buffer Gets	Executions	Gets per Exec	%Total	Elapsed Time (s)	%CPU	%IO	SQL Id	SQL Module	SQL Text
509,827,210	555	918,607.59	61.98	606.64	94.74	4.89	7yp93zzstn5gh	B1Manager@ccbdbpr1 (TNS V1-V3)	update (select /*+ index(B1_...
30,887,996	14	2,206,285.43	3.76	25.51	99.95	0.04	1hg2wcuapy3y3	JDBC Thin Client	select un_request.run_mod...

-->檢視commit頻率
這個部分可以檢視是否日誌切換較為頻繁，或者在進行著大量的事物處理，可以看看使用者進行commit的頻度

Instance Activity Stats

Statistic	Total	per Second	per Trans
user calls	7,073,740	11,777.75	216.38
user commits	32,485	54.09	0.99
user rollbacks	207	0.34	0.01

-->檢視系統負載
這個部分可以檢視系統級的一些指標，如果時間較長，就有多行的資料可以參考。總體來看iowait的比例不高。

Operating System Statistics - Detail

Snap Time	Load	%busy	%user	%sys	%idle	%iowait
31-Oct 13:20:02	38.14
31-Oct 13:30:03	39.55	21.82	17.03	3.41	78.18	0.19

-->檢視熱物件
可以透過segments by logical reads來得到一些比較熱的物件，可能是表，或者索引。
如果比例很高，可以透過這些熱物件從sql列表中排查一下，到底是哪些sql語句和這個熱物件相關。可能sql語句單獨執行很快，多個併發的程式時速度就會受到影響了。

Owner	Tablespace Name	Object Name	Subobject Name	Obj. Type	Logical Reads	%Total
APPO	INDXS01	CYCLE_GROUPS_PK		INDEX	41,559,296	5.05
EFWORK	DATAL01	OFFER		TABLE	20,566,400	2.50
APPO	DATAS01	STEP_INST		TABLE	10,610,368	1.29

-->檢視物理讀最高的物件
這個部分可以透過如下的方式查詢。排查表FILES_CONTROL的時候，發現sql列表中的一個對應的sql語句走了全表掃描，這個表本來資料量就有好幾百萬，走全表掃描還是可以完全避免的。

Segments by Physical Reads

Owner	Tablespace Name	Object Name	Subobject Name	Obj. Type	Physical Reads	%Total
APPO	DATAS01	STEP_INST		TABLE	10,101,327	25.38
APPO	DATAS01	FILES_CONTROL		TABLE	2,042,467	5.13
APPO	DATAS01	ACCOUNT		TABLE	920,202	2.31
APPO	DATAM01	DOCUMENT	P120_C10	TABLE PARTITION	905,729	2.28