在DB2應(yīng)用使用過(guò)程中，我們經(jīng)常會(huì)碰到應(yīng)用響應(yīng)時(shí)間很慢，甚至沒(méi)有響應(yīng)，但是應(yīng)用服務(wù)器可能并不是很繁忙，cpu利用率也非常低，引起這種狀況的原因有很多種，比如環(huán)境問(wèn)題，應(yīng)用資源泄漏，數(shù)據(jù)庫(kù)原因等等，本文主要是從一次應(yīng)用性能診斷過(guò)程來(lái)談?wù)勅绾瓮ㄟ^(guò)數(shù)據(jù)庫(kù)診斷應(yīng)用性能問(wèn)題。

問(wèn)題：

測(cè)試過(guò)程中發(fā)現(xiàn)應(yīng)用中某個(gè)跳轉(zhuǎn)頁(yè)面執(zhí)行時(shí)間比較長(zhǎng)，系統(tǒng)壓力不大，cpu利用很低，該頁(yè)面需要從cache中取數(shù)據(jù)，第一次的時(shí)候加載cache(從數(shù)據(jù)庫(kù)中查詢回?cái)?shù)據(jù)并cache)。

診斷：

頁(yè)面邏輯比較簡(jiǎn)單，我們先用loadrunner模擬并發(fā)測(cè)試一下這個(gè)頁(yè)面，然后再數(shù)據(jù)庫(kù)端捕獲sql執(zhí)行情況。

1、打開(kāi)db2監(jiān)控開(kāi)關(guān)

#db2 connect to eos

#db2 update monitor switches using statement on

#db2 reset monitor all

2、幾分鐘之后，我們收集sql統(tǒng)計(jì)快照

#db2 get snapshot for dynamic sql on eos > dysqlstatus.out

現(xiàn)在統(tǒng)計(jì)信息已經(jīng)存放在dysqlstatus.out中，你可以使用任意方便的文本處理工具查看，我一般用windows上的gvim來(lái)處理，打開(kāi)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

......

簡(jiǎn)單說(shuō)一下vi中的處理

:g!/Total execution time/d

只保留文本中的sql執(zhí)行時(shí)間，我們要按照?qǐng)?zhí)行時(shí)間來(lái)排序

通過(guò)vim的visual功能選擇執(zhí)行時(shí)間塊(等號(hào)后面的數(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

排序后的結(jié)果(部分)

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

可以看到最長(zhǎng)時(shí)間的sql total執(zhí)行時(shí)間耗費(fèi)了3797.905123s.

現(xiàn)在我們到dysqlstatus.out中去找這條語(yǔ)句

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

這條語(yǔ)句總共執(zhí)行了4602次，平均每次的執(zhí)行時(shí)間2S，而且這些數(shù)據(jù)應(yīng)該是被cache起來(lái)的 ;)

總結(jié)：

上面的方法簡(jiǎn)單總結(jié)了從數(shù)據(jù)庫(kù)層面對(duì)應(yīng)用的性能問(wèn)題診斷，希望對(duì)大家有所幫助，對(duì)于數(shù)據(jù)庫(kù)快照診斷問(wèn)題的思路對(duì)于任意數(shù)據(jù)庫(kù)通用