當你的SQL Server資料庫系統運行緩慢的時候,你或許多多少少知道可以使用SQL Server
Profiler(中文叫SQL事件探查器)工具來進行跟蹤和分析。是的,Profiler可以用來捕獲發送到SQL
Server的所有語句以及語句的執行效能相關資料(如語句的read/writes頁面數目,CPU的使用量,以及語句的duration等)以供以後
分析。但本文並不介紹如何使用Profiler
工具,而是將介紹如何使用read80trace(有關該工具見後面介紹)工具結合自訂的預存程序來提綱挈領地分析Profiler捕獲的Trace文
件,最終得出令人興奮的資料分析報表,從而使你可以高屋建瓴地最佳化SQL Server資料庫系統。
本文對那些需要分析SQL
Server大型資料庫系統效能的讀者如DBA等特別有用。在規模較大、應用邏輯複雜的資料庫系統中Profiler產生的檔案往往非常巨大,比如說在
Profiler中僅僅配置捕獲基本的語句事件,運行二小時後捕獲的Trace檔案就可能有GB級的大小。應用本文介紹的方法不但可以大大節省分析
Trace的時間和金錢,把你從Trace檔案的海量資料中解放出來,更是讓你對資料庫系統的訪問模式了如指掌,從而知道哪一類語句對效能影響最大,哪類
語句需要最佳化等等。
Profiler trace檔案效能分析的傳統方法以及局限
先說一下什麼是資料庫系統的訪問模式。除了可以使用Trace檔案解決如死結,阻塞,逾時等問題外,最常用也是最主要的功能是可以從Trace檔案中得到如下三個非常重要的資訊:
1.運行最頻繁的語句
2.最影響系統效能的關鍵語句
3.各類語句群佔用的比例以及相關效能統計資訊
本文提到的訪問模式就是上面三個資訊。我們知道,資料庫系統的模組是基本固定的,每個模組訪問SQL
Server的方式也是差不多固定的,具體到某個菜單,某個按鈕,都是基本不變的,所以,在足夠長的時間內,訪問SQL
Server的各類語句及其佔用的比例也基本上是固定的。換句話說,只要Profiler採樣的時間足夠長(我一般運行2小時以上),那麼從Trace文
件中就肯定可以統計出資料庫系統的訪問模式。每一個資料庫系統都有它自己獨一無二的訪問模式。分析Profiler
Trace檔案的一個重要目標就是找出資料庫系統的訪問模式。一旦得到訪問模式,你就可以在最佳化系統的時候做到胸有成竹,心中瞭然。可惜直到目前為止還沒
有任何工具可以方便地得到這些資訊。
傳統的Trace分析方法有兩種。一種是使用Profiler工具本身。比如說可以使用
Profiler的Filter功能過濾出那些已耗用時間超過10秒以上的語句,或按照CPU排序找出最耗費CPU的語句等。另一種是把Trace檔案匯入
到資料庫中,然後使用T-SQL語句來進行統計分析。這兩種方法對較小的Trace檔案是有效。但是,如果Trace檔案數目比較多比較大(如4個
500MB以上的trace檔案),那麼這兩種方法就有很大的局限性。其局限性之一是因為檔案巨大的原因,分析和統計都非常不易,常常使你無法從全域的高
度提綱挈領地掌握所有語句的執行效能。你很容易被一些語句迷惑而把精力耗費在上面,而實際上它卻不是真正需要關注的關鍵語句。局限性之二是你發現儘管很多
語句模式都非常類似(僅僅是執行時參數不同),卻沒有一個簡單的方法把他們歸類到一起進行統計。簡而言之,你無法輕而易舉地得到資料庫系統的訪問模式,無
法在最佳化的時候做到高屋建瓴,綱舉目張。這就是傳統分析方法的局限性。使用下面介紹的Read80trace工具以及自訂的預存程序可以克服這樣的局限
性。
Read80trace工具介紹以及它的Normalization 功能
Read80Trace工具是一個命令列工具。使用Read80Trace工具可以大大節省分析Trace檔案的時間,有事半功倍的效果。
Read80Trace的主要工作原理是讀取Trace檔案,然後對語句進行Normalize
(標準化),匯入到資料庫,產生效能統計分析的HTML頁面。另外,Read80trace可以產生RML檔案,然後OSTRESS工具使用RML檔案多
線程地重放Trace檔案中的所有事件。這對於那些想把Profiler捕獲的語句在另外一台伺服器上重放成為可能。本文不詳細介紹
Read80trace或OStress工具,有興趣的讀者請自行參閱相關資料,相關軟體可以從微軟網站下載(註:軟體名稱為RML)
http://www.microsoft.com/downloads/
我要利用的是Read80Trace的標準化功能。什麼是標準化?就是把那些語句模式類似,但參數不一樣的語句全部歸類到一起。舉例說Trace中有幾條語句如下:
select * from authors where au_lname = 'white'
select * from authors where au_lname = 'green'
select * from authors where au_lname = 'carson'
經過標準化後,上面的語句就變成如下的樣子:
select * from authors where au_lname = {str}
select * from authors where au_lname = {str}
select * from authors where au_lname = {str}
有了標準化後的語句,統計出資料庫系統的訪問模式就不再是難事。運行Read80trace 的時候我一般使用如下的命令列:
Read80trace –f –dmydb –Imytrace.trc
其中-f開關是不產生RML檔案,因為我不需要重放的功能。產生的RML檔案比較大,建議讀者如果不需要重放的話,也使用-f開關。
-d開關告訴read80trace把trace檔案的處理結果存到mydb資料庫中。我們後面建立的預存程序正是訪問read80trace在
mydb中產生的表來進行統計的。-I開關是指定要分析的的trace檔案名稱。Read80trace工具很聰明,如果該目錄下有Profiler產生的
一系列Trace檔案,如mytrace.trc,mytrace1.trc,mytrace2.trc等,那麼它會一一順序讀取進行處理。
除了上面介紹的外,Read80trace還有很多其它有趣的開關。比如說使用-i開關使得Read80trace可以從zip或CAB檔案中讀取
trace檔案,不用自己解壓。所有開關在Read80trace.chm中有詳細介紹。我最欣賞的地方是read80trace的效能。分析幾個GB大
小的trace檔案不足一小時就搞定了。我的電腦是一台記憶體僅為512MB的老機器,有這樣的效能我很滿意。
你也許會使用
read80trace分析壓力測試產生的trace檔案。我建議還是分析從生產環境中捕獲的Trace檔案為好。因為很多壓力測試工具都不能夠真正類比
現實的環境,其得到的trace檔案也就不能真實反映實際的情況。甚至有些壓力測試工具是迴圈執行自己寫的語句,更不能反映準確的訪問模式。建議僅僅把壓
力測試產生的trace作為參考使用。
使用預存程序分析Normalize後的資料
有了標準化後的語句就可以使用預存程序進行統計分析了。分析的基本思想是把所有模式一樣的語句的Reads,CPU和Duration做group by統計,得出訪問模式資訊:
1.某類語句的總共執行次數,平均讀頁面數(reads)/平均CPU時間/平均執行時間等。
2.該類語句在所有語句的比例,如執行次數比例,reads比例,CPU比例等。
預存程序的定義以及說明如下:
Create procedure usp_GetAccessPattern 8000
@duration_filter int=-1 --傳入的參數,可以按照語句執行的時間過濾統計
as begin
/*首先得到全部語句的效能資料的總和*/
declare @sum_total float,@sum_cpu float,@sum_reads float,@sum_duration float,@sum_writes float
select @sum_total=count(*)*0.01,--這是所有語句的總數。
@sum_cpu=sum(cpu)*0.01, --這是所有語句耗費的CPU時間
@sum_reads=sum(reads)*0.01, --這是所有語句耗費的Reads數目,8K為單位。
@sum_writes=sum(writes)*0.01,--這是所有語句耗費的Writes數目,8K為單位。
@sum_duration=sum(duration)*0.01--這是所有語句的執行時間總和。
from tblBatches --這是Read80Trace產生的表,包括了Trace檔案中所有的語句。
where duration>=@duration_filter --是否按照執行時間過濾
/*然後進行Group by,得到某類語句佔用的比例*/
Select ltrim(str(count(*))) exec_stats,''+ str(count(*)/@sum_total,4,1)+'%' ExecRatio,
ltrim(str(sum(cpu)))+' : '++ltrim(str(avg(cpu))) cpu_stats,''+str(sum(cpu)/@sum_cpu,4,1)+'%' CpuRatio,
ltrim(str(sum(reads) ))+' : '+ltrim(str(avg(reads) )) reads_stats,''+str(sum(reads)/@sum_reads,4,1) +'%' ReadsRatio ,
--ltrim(str(sum(writes) ))+' : '+ltrim(str(avg(writes) )) --writes_stats,''+str(sum(writes)/@sum_writes,4,1) +'%)',
ltrim(str(sum(duration) ))+' : '+ltrim(str(avg(duration))) duration_stats,''+str(sum(duration)/@sum_duration,4,1)+'%' DurRatio ,
textdata,count(*)/@sum_total tp,sum(cpu)/@sum_cpu cp,sum(reads)/@sum_reads rp,sum(duration)/@sum_duration dp
into #queries_staticstics from
/* tblUniqueBatches表中存放了所有標準化的語句。*/
(select reads,cpu,duration,writes,convert(varchar(2000),NormText)textdata from tblBatches
inner join tblUniqueBatches on tblBatches.HashId=tblUniqueBatches.hashid where duration>@duration_filter
) B group by textdata --這個group by很重要,它對語句進行歸類統計。
print 'Top 10 order by cpu+reads+duration'
select top 10 * from #queries_staticstics order by cp+rp+dp desc
print 'Top 10 order by cpu'
select top 10 * from #queries_staticstics order by cp desc
print 'Top 10 order by reads'
select top 10 * from #queries_staticstics order by rp desc
print 'Top 10 order by duration'
select top 10 * from #queries_staticstics order by dp desc
print 'Top 10 order by batches'
select top 10 * from #queries_staticstics order by tp desc
End
考慮到輸出結果橫向較長,預存程序中把writes去掉了。這是因為大部分的資料庫系統都是Reads為主的。你可以輕易的修改預存程序把write也包括進去。
預存程序並不複雜,很容易理解。可以看到統計的結果放在queries_staticstics表中,然後按照不同的條件排序後輸出。舉例說:
select top 10 * from #queries_staticstics order by cp desc
上面的語句將把queries_staticstics表中的記錄按照某類語句佔用總CPU量的比例cp(即sum(cpu)/@sum_cpu)進行排序輸出。這讓你在分析伺服器CPU效能問題的時候快速定位哪一類語句最耗CPU資源,從而對症下藥。
現在讓我們看一個執行個體的輸出:
Use mydb
Exec usp_GetAccessPattern
/*你可以輸入一個執行時間作為過濾參數,毫秒為單位。如usp_GetAccessPattern 1000*/
輸出結果 1所示(是部分結果,另外,因為原輸出結果橫向很長,為方便閱讀,把結果從中截斷為兩部分):
圖 1:輸出結果採樣一
上面的例子採樣於一家大型公司的業務系統。該系統的問題是應用程式運行緩慢,SQL Server
伺服器的CPU高居不下(8個CPU都在90%~100%間波動)。我使用PSSDIAG工具採樣2小時左右的資料,然後運行read80trace和
usp_GetAccessPattern得出上面的結果。報表一目瞭然。預存程序DBO.x_DEDUP_PROC在兩小時內共運行75次,卻佔用了
90.8%的CPU資源,94.6%的Reads,從訪問模式的角度,該預存程序正是導致CPU高和系統效能慢的關鍵語句。一旦最佳化了該預存程序,系統的
效能問題將迎刃而解。你也許有疑問,兩小時內共運行75次,不是很頻繁啊。其實你看看這條預存程序的平均CPU時間是681961毫秒,大概11分鐘左
右。也就是說一個CPU兩小時內最多可以執行(60*2)/11=10條左右,該系統總共有8個CPU,即使全部CPU都用來運行該語句,那麼最多也就是
10*8=80條左右。上面執行總數是75,說明該預存程序一直在連續不斷地運行。
那麼該系統運行最頻繁的語句是什麼呢?我從結果中摘取另外一部分如下(圖 2):
圖 2:輸出結果採樣二
從上表可以看出,最頻繁啟動並執行語句是
USE xb SET QUOTED_IDENTIFIER,ANSI_NULL_DFLT_ON…
顯然這是一條執行環境配置語句,沒有參考價值。倒是另外兩條佔用語句總數8.2%的語句值得關註:
SELECT COUNT(*) FROM x_PROCESS_STATS WHERE PROCESS……
SELECT COUNT(*) FROM x_PROCESS_STATS WHERE PROCESS……
在這個例子中,因為關鍵語句DBO.x_DEDUP_PROC非常突出,甚至上面的兩條語句都可以忽略了。
讓我們再多看一個例子(圖 3):
圖 3:輸出結果採樣三
從上面的例子中, 可以得出關鍵的語句是:
SELECT COUNT(*) FROM GTBL7MS
SELECT CaseNO FROM PATIENTDATA_sum WHERE MRN = @P1
後續的檢查發現相關的表沒有有效索引,加上索引後效能立即整體地提高了不少.。解決了這兩個語句,需要使用同樣的手段繼續分析和最佳化,直到系統的效能能
夠接受為止.。注意效能調優是一個長期的過程,你不太可能一兩天就可以把所有的問題都解決。也許一開始可以解決80%的問題,但是後面20%的問題卻需要
另外80%的時間。
使用usp_GetAccessPattern的一些技巧
usp_GetAccessPattern的輸出報表包含了非常豐富的資訊。分析報表的時候需要有大局觀。你也可以有目的性地選擇你需要的資訊。如果是
CPU效能瓶頸的系統,那麼你需要關注CPU佔用比例高的那類語句。如果是磁碟IO出現效能瓶頸那麼你需要找到那些Reads佔用比例大而且平均
reads也很高的語句。需要注意的是有時候運行頻繁的語句未必就是你需要關注的關鍵語句。一個最理想的情況是關鍵語句正好就是最頻繁的語句。有時候即使
最頻繁語句佔用的資源比例不高,但如果還可以最佳化,那麼因為放大效應,微小的最佳化也會給系統帶來可觀的好處。
在使用
usp_GetAccessPattern的時候多結合@duration_filter參數使用。因為參數以毫秒為單位,建議參數不要小於1000,而
應該是1000的倍數
如3000,5000等。該參數常常會給出非常有意思的輸出。該輸出和不帶參數啟動並執行結果會有某些重疊。重疊出現的語句通常正是需要關注的語句。要注意運
行最多最密的語句未必有超過1000毫秒的執行時間,所有帶參數啟動並執行結果有可能不包括最頻繁語句。我常常同時交叉分析四個結果,一個是不帶參數運行得到
的,另三個分別是使用1000,3000和5000毫秒為參數啟動並執行結果。比較分析這四個結果往往使我對資料庫系統的訪問模式有非常清晰透徹的理解。
運行預存程序時你也許會碰到int整數溢出的錯誤。這是因為表tblBatches 中的reads,cpu 和writes欄位是int而不是bigint。可以運行如下語句進行修正:
alter table tblBatches alter column reads bigint
alter table tblBatches alter column cpu bigint
alter table tblBatches alter column writes bigint
修正後溢出問題就會解決。
蛇足:哪個是HOT 資料庫?
本文到這裡就基本上結束了。你已經知道如何使用Read80Trace和usp_GetAccessPattern得到資料庫系統的訪問模式,以及如何從全域的高度去分析訪問模式報表,從而在最佳化系統的時候做到提綱挈領,胸有成竹。
除此之外,你還可以應用類似的分析思想得到每個資料庫的佔用資源比例。這對於SQL Server有多個資料庫的情況非常有用。從報表中你可以立即知道哪個資料庫是最HOT最消耗系統資源的資料庫。語句如下:
print 'group by dbid'
declare @sum_total float,@sum_cpu float,@sum_reads float,@sum_duration float,@sum_writes float
select @sum_total=count(*)*0.01,@sum_cpu=sum(cpu)*0.01,@sum_reads=sum(reads)*0.01,@sum_writes=sum(writes)*0.01,
@sum_duration=sum(duration)*0.01 from tblBatches
select dbid,
ltrim(str(count(*))) exec_stats,''+ str(count(*)/@sum_total,4,1)+'%' ExecRatio,
ltrim(str(sum(cpu)))+' : '++ltrim(str(avg(cpu))) cpu_stats,''+str(sum(cpu)/@sum_cpu,4,1)+'%' CpuRatio ,
ltrim(str(sum(reads) ))+' : '+ltrim(str(avg(reads) )) reads_stats,''+str(sum(reads)/@sum_reads,4,1) +'%' ReadsRatio ,
ltrim(str(sum(duration) ))+' : '+ltrim(str(avg(duration))) duration_stats,''+str(sum(duration)/@sum_duration,4,1)+'%' DurRatio ,
count(*)/@sum_total tp,sum(cpu)/@sum_cpu cp,sum(reads)/@sum_reads rp,sum(duration)/@sum_duration dp
into #queries_staticstics_groupbydb from
(select reads,cpu,duration,writes,convert(varchar(2000),NormText)textdata,dbid from tblBatches
inner join tblUniqueBatches on tblBatches.HashId=tblUniqueBatches.hashid
) b group by dbid order by sum(reads) desc
select dbid,ExecRatio batches,CPURatio CPU,ReadsRatio Reads,DurRatio Duration
from #queries_staticstics_groupbydb
下面是一個上面語句結果的一個例子:
dbid batches CPU Reads Duration
------ ------- ----- ------- --------
37 21.1% 18.7% 29.1% 27.1%
33 12.7% 32.4% 19.5% 24.8%
36 5.6% 28.3% 15.6% 26.1%
20 53.9% 2.9% 14.2% 2.1%
22 0.8% 7.2% 13.2% 6.6%
25 1.0% 3.6% 5.4% 3.5%
16 0.0% 1.5% 1.9% 0.7%
35 2.0% 2.7% 1.8% 5.7%
7 0. 1% 0.1% 1.1% 0.3%
上面的結果明確地告訴我們ID為37,33和36的資料庫是最活躍的資料庫。一個有趣的事實是資料庫20發出的語句總數比例是53.9%,但是其佔用的系統資源比例卻不高。