作者：tacy lee
在應用使用過程中，我們經常會碰到應用響應時間很慢，甚至沒有響應，但是應用服務器可能并不是很繁忙，cpu利用率也非常低，引起這種狀況的原因有很多種，比如環(huán)境問題，應用資源泄漏，數(shù)據(jù)庫原因等等，本文主要是從一次應用性能診斷過程來談談如何通過數(shù)據(jù)庫診斷應用性能問題。
問題：
測試過程中發(fā)現(xiàn)應用中某個跳轉頁面執(zhí)行時間比較長，系統(tǒng)壓力不大，cpu利用很低，該頁面需要從cache中取數(shù)據(jù)，第一次的時候加載cache（從數(shù)據(jù)庫中查詢回數(shù)據(jù)并cache）。
診斷：
頁面邏輯比較簡單，我們先用loadrunner模擬并發(fā)測試一下這個頁面，然后再數(shù)據(jù)庫端捕獲sql執(zhí)行情況。
1、打開db2監(jiān)控開關
#db2 connect to eos
#db2 update monitor switches using statement on
#db2 reset monitor all
2、幾分鐘之后，我們收集sql統(tǒng)計快照
#db2 get snapshot for dynamic sql on eos > dysqlstatus.out
現(xiàn)在統(tǒng)計信息已經存放在dysqlstatus.out中，你可以使用任意方便的文本處理工具查看，我一般用windows上的gvim來處理，打開dysqlstatus.out
Number of executions = 1
Number of compilations = 1
Worst preparation time (ms) = 2
Best preparation time (ms) = 2
Internal rows deleted = 0
Internal rows inserted = 0
Rows read = 2
Internal rows updated = 0
Rows written = 0
Statement sorts = 0
Statement sort overflows = 0
Total sort time = 0
Buffer pool data logical reads = Not Collected
Buffer pool data physical reads = Not Collected
Buffer pool temporary data logical reads = Not Collected
Buffer pool temporary data physical reads = Not Collected
Buffer pool index logical reads = Not Collected
Buffer pool index physical reads = Not Collected
Buffer pool temporary index logical reads = Not Collected
Buffer pool temporary index physical reads = Not Collected
Total execution time (sec.ms) = 0.000377
Total user cpu time (sec.ms) = 0.010000
Total system cpu time (sec.ms) = 0.000000
Statement text = select ACTIVITYDEFID,ACTIVITYINSTID from wfworkitem where
PROCESSINSTID=104199 and CURRENTSTATE = 4
......
簡單說一下vi中的處理
:g!/Total execution time/d
只保留文本中的sql執(zhí)行時間，我們要按照執(zhí)行時間來排序
通過vim的visual功能選擇執(zhí)行時間塊（等號后面的數(shù)字），然后排序
Total execution time (sec.ms) = 0.050590
Total execution time (sec.ms) = 0.000170
Total execution time (sec.ms) = 0.000247
Total execution time (sec.ms) = 0.000292
Total execution time (sec.ms) = 0.000474
Total execution time (sec.ms) = 0.000330
Total execution time (sec.ms) = 0.000348
Total execution time (sec.ms) = 0.000279
Total execution time (sec.ms) = 0.000385
Total execution time (sec.ms) = 0.000296
Total execution time (sec.ms) = 0.000261
Total execution time (sec.ms) = 0.000195
Total execution time (sec.ms) = 0.000226
Total execution time (sec.ms) = 0.000227
Total execution time (sec.ms) = 0.000193
......
:'<,'>!sort
排序后的結果（部分）
Total execution time (sec.ms) = 2.027776
Total execution time (sec.ms) = 2.203624
Total execution time (sec.ms) = 2.504677
Total execution time (sec.ms) = 2.951256
Total execution time (sec.ms) = 3.119875
Total execution time (sec.ms) = 3.303277
Total execution time (sec.ms) = 3.303517
Total execution time (sec.ms) = 4.017133
Total execution time (sec.ms) = 4.043329
Total execution time (sec.ms) = 4.252125
Total execution time (sec.ms) = 4.400952
Total execution time (sec.ms) = 4.606765
Total execution time (sec.ms) = 5.208087
Total execution time (sec.ms) = 5.778598
Total execution time (sec.ms) = 8.117470
Total execution time (sec.ms) = 9797.905136
可以看到最長時間的sql total執(zhí)行時間耗費了3797.905123s.
現(xiàn)在我們到dysqlstatus.out中去找這條語句
Number of executions = 4602
Number of compilations = 4294967295
Worst preparation time (ms) = 2
Best preparation time (ms) = 2
Internal rows deleted = 0
Internal rows inserted = 0
Rows read = 2963688
Internal rows updated = 0
Rows written = 0
Statement sorts = 0
Statement sort overflows = 0
Total sort time = 0
Buffer pool data logical reads = Not Collected
Buffer pool data physical reads = Not Collected
Buffer pool temporary data logical reads = Not Collected
Buffer pool temporary data physical reads = Not Collected
Buffer pool index logical reads = Not Collected
Buffer pool index physical reads = Not Collected
Buffer pool temporary index logical reads = Not Collected
Buffer pool temporary index physical reads = Not Collected
Total execution time (sec.ms) = 9797.905136
Total user cpu time (sec.ms) = 9.290000
Total system cpu time (sec.ms) = 1.230000
Statement text = select * from XXXX_T_CNFACTIVITYDEF
這條語句總共執(zhí)行了4602次，平均每次的執(zhí)行時間2S，而且這些數(shù)據(jù)應該是被cache起來的 ；）
總結：
上面的方法簡單總結了從數(shù)據(jù)庫層面對應用的性能問題診斷，希望對大家有所幫助，對于數(shù)據(jù)庫快照診斷問題的思路對于任意數(shù)據(jù)庫通用
補充一個unix上腳本處理方式：
sqlsort.sh
awk 'BEGIN{RS="";FS="\n";ORS="\n"};/Statement text/{print $1, $21, $24}' $1 | awk '$5 > 0 {print "AvgTime:", $11/$5, "\t", $0}'| sort -n | head -n $2|awk '{print $0, "\n"}'
使用：#sqlsort.sh dysqlstate.out 10（顯示Top ten）