事務是指用戶在客戶端做一種或多種業(yè)務所需要的操作集,通過事務函數(shù)可以標記完成該業(yè)務所需要的操作內(nèi)容;另一方面事務可以用來統(tǒng)計用戶操作的響應時間,事務響應時間是通過記錄用戶請求的開始時間和服務器返回內(nèi)容到客戶時間的差值來計算用戶操作響應時間的,如圖3.159所示。
圖3.159 事務響應時間計算方式
這里的響應時間不包含客戶端GUI時間(例如瀏覽器解釋頁面所消耗的時間)。
前面說響應時間是服務器返回和用戶請求發(fā)出之間的時間差,那么得到這個時間就夠了嗎?
例如:現(xiàn)在有一場跑步比賽。當比賽完成后,可以得到每位運動員跑完整個比賽所需要消耗的時間,現(xiàn)在需要分析誰的起跑好、誰的沖刺好,能分析出來嗎?答案是不能,雖然得到了最重要的完成比賽的響應時間,但是這對分析和優(yōu)化幾乎沒有作用,因為只知道了結果而不知道過程。跑步的時間是由起跑、中途、沖刺等時間組成的,如果想要進行分析優(yōu)化,必須先了解各個階段所花費的時間和速度以及各個運動員的優(yōu)缺點。
對于軟件來說,通過事務得到的系統(tǒng)響應時間也是由非常多的部分組成的,一般來說響應時間由網(wǎng)絡時間、服務器處理時間、網(wǎng)絡延遲三大部分組成。先來看看當一個客戶端發(fā)出請求到服務器返回需要經(jīng)歷哪些路徑,如圖3.160所示。
圖3.160 事務響應時間組成
1.網(wǎng)絡時間
客戶端發(fā)出請求首先通過網(wǎng)絡來到Web Server上(消耗時間為N1);然后Web Server將處理后的請求發(fā)送給App Server(消耗時間為N2);App Server將操作數(shù)據(jù)指令發(fā)送給Database (消耗時間為N3);Database服務器將查詢結果數(shù)據(jù)發(fā)送回App Server(消耗時間為N4);App Server將處理后的頁面發(fā)給Web Server(消耗時間為N5);最后Web Server將HTML轉(zhuǎn)發(fā)到客戶端(消耗時間為N6)。這里的Nx都是網(wǎng)絡傳輸上的時間開銷,沒有計算業(yè)務處理所需要花費的時間。
2.服務器處理時間
另外一個方面還要考慮各個服務器處理所需要的時間WT、AT、DT。
3.網(wǎng)絡延遲
除了上面兩種時間開銷以外,還要考慮網(wǎng)絡延遲的問題。
所以最終的響應時間組成為:
響應時間 = 網(wǎng)絡延遲時間 + WT+AT+DT +(N1+N2+N3)+(N4+N5+N6)+ WT+AT+DT
也可以簡單認為響應時間由網(wǎng)絡開銷(前端)和服務器端開銷(后端)兩大部分組成,如圖3.161所示。
那么這些消耗的時間都花在什么事情上了呢?影響網(wǎng)絡的因素一般包括以下內(nèi)容:
1.前端Network
Ÿ DNS Lookup
Ÿ Time to connect
Ÿ Time to first buffer
Ÿ Network Time
Ÿ Download Time
Ÿ SSL handshake
Ÿ FTP authentication
Ÿ Client Time
Ÿ Error Time
Ÿ 網(wǎng)絡延遲
2.后端服務
Ÿ Web Server
Ø Servlet Time
Ø Method Time
Ø 靜態(tài)動態(tài)壓縮
Ÿ App Server
Ø EJB Time
Ø Method Time
Ø JNDI Lookup
Ÿ Database Server
Ø JDBC Time
Ø Connect Time
Ø Execute Time
這里會發(fā)現(xiàn)響應時間的組成是非常復雜的,當性能問題出現(xiàn)時,想要定位到具體的代碼級別是相當困難的。
通過事務監(jiān)控響應時間,需要做的就是在請求的發(fā)出前添加一個事務開始的計數(shù)器,在請求結束的地方添加一個事務結束的計數(shù)器,VuGen會自動計算函數(shù)間的時間差。
通過工具欄上的事務按鈕即可完成事務的添加操作,在請求之前單擊插入事務開始按鈕,如圖3.162所示。
在彈出對話框中填寫事務名稱mainpage,如圖3.163所示。
圖3.162 插入事務開始按鈕 圖3.163 設置事務名稱
單擊OK按鈕后,可以得到事務開始的函數(shù):
lr_start_transaction("mainpage");
通過這條語句開始了一個叫做mainpage的事務,然后在請求后添加一個事務結束函數(shù),單擊插入事務結束按鈕,如圖3.164所示。
這里提供了幾個選項,選擇LR_AUTO 由VuGen自動判斷狀態(tài),如圖3.165所示。
圖3.164 插入事務結束按鈕 圖3.165 設置事務狀態(tài)判斷為LR_AUTO
這樣就生成了一個事務結束的函數(shù):
lr_end_transaction("mainpage", LR_AUTO);
這里事務的開始和結束名稱需要配對。
事務設置結束,通過這兩個函數(shù)完成了對事務的設計,運行腳本來看看效果。腳本如下所示:
Action()
{
lr_start_transaction("mainpage");
web_url("51testing","URL=http://bbs.51testing.com",LAST);
lr_end_transaction("mainpage", LR_AUTO);
return 0;
}
在日志中可以看到以下信息:
Action.c(3): Notify: Transaction "mainpage" started.
//請求發(fā)送返回的相關日志
Action.c(5): Notify: Transaction "mainpage" ended with "Pass" status (Duration: 5.9749).
事務結束的說明中包含了請求所花費的時間為Duration=5.9749秒和事務結束的狀態(tài)。通過事務可以獲得每個操作所消耗的準確時間,例如查詢、登錄、刪除操作。但是對于性能分析來說,這個時間還是太大了,無法有效地幫助我們定位性能瓶頸,LoadRunner能解決這個問題嗎?抱歉,LoadRunner只能對自己發(fā)出的請求和服務器返回的內(nèi)容進行網(wǎng)絡級別的分析,也就是說LoadRunner能夠分析的時間為客戶到WWW服務器的時間N1和WWW服務器返回到客戶的時間 N6。這些時間主要和網(wǎng)絡速度有關,可以用一個LoadRunner的名稱來解釋,叫做Web Page Breakdown,相關的具體分析可以參考第5.3.5節(jié)。
也就是說VuGen可以分析的時間只有客戶端到Web Server之間的部分,后面從Web Server到App Server再到Database Server的時間只能得到一個總和。
事務狀態(tài)
在默認情況下使用LR_AUTO來作為事務狀態(tài),對于一個事務有以下4個狀態(tài)可以選擇。
1.LR_AUTO
LR_AUTO是指事務的狀態(tài)由系統(tǒng)自動根據(jù)默認規(guī)則來判斷,結果為PASS/FAIL/STOP。
2.LR_PASS
LR_PASS指事務是以PASS狀態(tài)通過的,說明該事務正確地完成了,并且記錄下對應的時間,這個時間就是指做這件事情所需要消耗的響應時間。
3.LR_FAIL
LR_FAIL是指事務以FAIL狀態(tài)結束,該事務是一個失敗的事務,沒有完成事務中腳本應該達到的效果,得到的時間不是正確操作的時間,這個時間在后期的統(tǒng)計中將被獨立統(tǒng)計。
4.LR_STOP
LR_STOP將事務以STOP狀態(tài)停止。
事務的PASS和FAIL狀態(tài)會在場景的對應計數(shù)器中記錄,包括通過的次數(shù)和事務的響應時間,方便后期分析該事務的吞吐量以及響應時間的變化情況。
事務和子事務
在VuGen中可以通過事務來完成一組操作的響應時間監(jiān)控,如果想監(jiān)控一個事務中某一步操作的響應時間,就需要使用子事務來完成(當然也可以直接使用事務嵌套)。
Lr_start_sub_transaction("子事務名","父事務名");
Lr_end_sub_transaction("子事務名","子事務狀態(tài)");
子事務雖然和父事務很像,但是父事務支持的很多函數(shù),在子事務中都無法實現(xiàn),所以應酌情考慮。
例如:需要做一個登錄的事務,想知道打開登錄頁面和登錄操作的時間,就可以使用子事務。
lr_start_transaction("login");
lr_start_sub_transaction("loginpage","login");
//打開登錄頁面
lr_end_sub_transaction("loginpage",LR_AUTO);
lr_start_sub_transaction("submitlogin","login");
//提交登錄表單
lr_end_sub_transaction("submitlogin",LR_AUTO);
lr_end_transaction("login",LR_AUTO);
這樣可以得到3個事務的時間,并且清楚地得到打開頁面和登錄操作以及整個操作的時間。
事務相關的函數(shù)
lr_get_transaction_duration("事務名")
//獲得對應事務達到該函數(shù)運行位置時持續(xù)的時間,返回double類型
lr_get_transaction_wasted_time("事務名")
//獲得對應事務達到該函數(shù)運行位置時的wasted時間,返回double類型
lr_wasted_time(毫秒)
//為一個事務添加wasted時間,無返回
lr_stop_transaction("事務名")
//將一個事務暫停,該函數(shù)后的操作都不會被記入事務時間
lr_resume_transaction("事務名")
//將暫停的事務恢復
一般情況下都可以十分簡便地獲得請求的相應時間,但是對于下載操作來說就并不是那么方便了,這個時候需要利用一個web_get_int_property()函數(shù)來解決。例如想獲得一個下載操作的響應時間,可以這樣寫:
Action()
{
int i;
lr_start_transaction("download");
web_url("LoadRunner","URL=http://127.0.0.1/loadrunner.iso",LAST);//下載操作的請求
i=web_get_int_property(HTTP_INFO_DOWNLOAD_SIZE);
if(i>5000)//當下載的文件大小大于5000個字節(jié)時認為下載成功,否則失敗
lr_end_transaction("download",LR_PASS);
else
lr_end_transaction("download",LR_FAIL);
}
當進行下載操作時,服務器會返回該下載操作的文件大小,所以只需要獲得該信息即可,如果還希望對下載時的速度進行測試,那么需要配合關聯(lián)函數(shù)將返回的內(nèi)容保存到本地才能實現(xiàn)。一般來說對于下載操作的性能測試集中在需要多少時間彈出下載對話框,而后面的內(nèi)容其實是屬于網(wǎng)絡帶寬的問題了。另一方面現(xiàn)在很少使用IE進行直接下載,而采用迅雷一類的P2P下載工具,所以很少考慮具體下載文件操作對網(wǎng)絡和服務器讀寫操作的影響。
一個事務的時間是指持續(xù)時間,事務會完全記錄下從事務開始到事務結束之間的時間差,那么事務的時間能真實地反映業(yè)務操作的時間嗎?不能,就好像人用手按秒表來記錄短跑時間一樣,得出的時間并不是完全準確,存在觀察的誤差和操作的誤差,對于一個事務時間來說,一般由四部分組成,如圖3.166所示。
響應時間
這是事務的目的,通過事務記錄業(yè)務操作所消耗的響應時間。
事務自身時間
事務中哪怕沒有操作,也是需要時間的,不過這個時間一般在0.01秒左右,所以可以忽略。
lr_start_transaction("thinktime");
lr_end_transaction("thinktime", LR_AUTO);
運行上面的腳本后,可以看到:
Action.c(5): Notify: Transaction "thinktime" started.
Action.c(9): Notify: Transaction "thinktime" ended with "Pass" status (Duration: 0.0121).
思考時間(Think Time)
Think Time是LoadRunner提供的一種模擬用戶等待的方式,通過lr_think_time()函數(shù)實現(xiàn)。在函數(shù)內(nèi)寫入對應的時間(單位是秒),當腳本在Controller中運行到該函數(shù)時就會等待相應的時間。注意在VuGen中,回放Think Time默認關閉。
Think Time在進行性能測試的時候需要打開,只有這樣每個虛擬用戶才是真正按照用戶的操作速度來完成請求,才能得到在真實情況下的系統(tǒng)數(shù)據(jù)。如果不打開Think Time,測試獲得的數(shù)據(jù)是在全負載下的一些理論峰值數(shù)據(jù)。
那么Think Time 在事務中如何影響事務時間呢?編寫如下腳本:
lr_start_transaction("thinktime");
lr_think_time(5);
lr_end_transaction("thinktime", LR_AUTO);
在Run-time Settings中設置Think Time,啟用Replay Think Time功能,運行之后可以看到以下結果:
Action.c(5): Notify: Transaction "thinktime" started.
Action.c(7): lr_think_time: 5.00 seconds.
Action.c(9): Notify: Transaction "thinktime" ended with "Pass" status (Duration: 5.0254 Think Time: 4.9995).
所以Think Time 會被算在事務的時間內(nèi),不過在Analysis中可以設置過濾規(guī)則將其扣除,另外我們也建議盡量不要在事務內(nèi)使用lr_think_time()函數(shù)。
浪費時間(Wasted Time)
在使用事務的時候,經(jīng)常會看到在事務日志中有Wasted Time。Wasted Time是指事務中應該扣除的由于其他原因?qū)е碌臅r間浪費。在默認情況下LoadRunner會將自身腳本運行浪費的時間自動記入Wasted Time。例如執(zhí)行關聯(lián)、檢查點等函數(shù)的時間。
除了腳本自身浪費的時間,某些時候使用C語言等外部接口進行處理所消耗的時間也會影響事務的時間,而這個時間LoadRunner無法處理,在這種情況下就需要人為地計算第三方時間開銷,并且將這個開銷的時間記入Wasted Time中。
運行一下下面的代碼:
Action()
{
int i;
int baseIter = 100;
char dude[1000];
merc_timer_handle_t timer;
// Examine the total elapsed time of the action
//Start transaction
lr_start_transaction("Demo");
timer=lr_start_timer();
for (i=0;i<=baseIter*1000;i++) {
sprintf(dude,"This is the way we waste time in a script = %d", i);
}
wasteTime=lr_end_timer(timer);
lr_wasted_time(wasteTime*1000);
lr_end_transaction("Demo", LR_AUTO);
return 0;
}
其中,lr_start_timer()是一個LoadRunner自帶的時間計數(shù)器,它和lr_end_timer()相對應,能夠返回這兩個函數(shù)間的時間差。
運行腳本后,等待一段時間腳本運行結束,可以看到以下日志。
Action.c(18): Notify: Transaction "Demo" started.
Action.c(27): wasted time is 85.860000
Action.c(28): Notify: Transaction "Demo" ended with "Pass" status (Duration: 85.8772 Wasted Time: 85.8600).
通過上面這個日志可以看到,在VuGen運行腳本的時候這個1000次的C語言操作所消耗的時間會被算在Transaction時間內(nèi),導致Transaction的時間變長。當通過lr_start_timer()計時函數(shù)將這個消耗時間加入Wasted Time后,這個腳本就能正確地計算出事務的時間和該事務時間的Wasted Time了。當在場景中運行的時候,事務的響應時間會自動扣除Wasted Time。
為了確保響應時間的正確,需要扣除在運行腳本時自身的時間消耗,事務中盡量避免出現(xiàn)非請求的處理內(nèi)容,如果無法避免請使用lr_wasted_time()函數(shù)將多余的時間開銷扣除。
例如這樣的腳本:
merc_timer_handle_t timer; //變量聲明
lr_start_transaction("Demo");
timer=lr_start_timer();
lr_load_dll("getkey.dll");
lr_save_string(getrandkey(),"key");
//通過調(diào)用dll獲得密鑰
wasteTime=lr_end_timer(timer);
lr_wasted_time(wasteTime*1000);
lr_end_transaction("Demo", LR_AUTO);
計算密鑰是很消耗時間的,那么可以使用timer這個變量來記錄計算的時間,并將這個時間從整個事務中扣除。
在計算Wasted Time時不要直接使用lr_wasted_time()覆蓋,而忘了加上腳本中LoadRunner函數(shù)的自身時間。通過lr_get_transaction_wasted_time()函數(shù)可以獲得事務自身的Wasted Time,將這個時間累加上第三方統(tǒng)計的Wasted Time再通過lr_wasted_time()函數(shù)覆蓋。
前面都是使用LR_AUTO來自動判斷事務狀態(tài),現(xiàn)在來做一個腳本,看看LoadRunner的事務是如何自動判斷狀態(tài)的。
錄制一個論壇注冊用戶的腳本,在提交注冊表單處添加事務開始及結束標志,然后回放該腳本。事務的結果是PASS還是FAIL呢?雖然回放腳本注冊用戶是失敗的(該用戶已經(jīng)存在),但是事務還是在PASS狀態(tài)下完成了,而且會發(fā)現(xiàn)事務的持續(xù)時間很短。正常情況下注冊一個用戶到刷新首頁一般都要2秒,現(xiàn)在只需要0.3秒。這是因為當服務器判斷到該用戶已存在后,就沒有了數(shù)據(jù)插入和等待1秒刷新首頁的操作,而是直接返回錯誤提示頁面。這個0.3秒是系統(tǒng)處理錯誤的時間而不是注冊用戶所需要的時間。
LR_AUTO也是根據(jù)服務器的返回狀態(tài)信息來決定事務是以LR_PASS狀態(tài)通過還是以LR_FAIL狀態(tài)結束,只要服務器返回頁面,那么事務就會認為請求成功發(fā)出去了,服務器看懂了請求也返回了內(nèi)容,自然事務是PASS狀態(tài)了。
這樣由于事務自動判斷的錯誤,導致雖然操作是失敗的,但得到了一個響應時間,并且這個響應時間又沒有正確反映出做這件事情的真正時間,最終就會影響到性能測試得到的數(shù)據(jù)。
記得在論壇上就有朋友問過這樣的問題,為什么系統(tǒng)在用戶越來越多的情況下,響應時間不增反減?這種現(xiàn)象很有可能就是沒有使用手工事務導致的結果。
對于這種情況就需要手工來判斷操作是否成功,通過web_reg_find()檢查點函數(shù)來檢查頁面是否返回正確,然后通過rowcount的參數(shù)值來進行事務狀態(tài)判斷,做到智能判斷事務結果。
例如:檢查點函數(shù)的rowcount保存在參數(shù)loginst中,那么事務的狀態(tài)就應該這樣判斷:
lr_start_transaction("login");
web_reg_find("Search=Body",
"SaveCount=loginst",
"Text=登錄失敗",
LAST);
//登錄請求
If(atoi(lr_eval_string("{loginst}"))>=1))
lr_end_transaction("login", LR_FAIL);
else
lr_end_transaction("login",LR_PASS);
通過檢查點來檢查登錄后頁面是不是存在“登錄失敗”這樣的內(nèi)容,如果存在那么loginst的值就大于等于1,然后把loginst的值取出來和1做比較,如果大于1那么就是登錄失敗,否則就是登錄成功。
參數(shù)不能和值做比較,所以要先通過lr_eval_string()函數(shù)將其轉(zhuǎn)化成字符串,然后再通過atoi()函數(shù)轉(zhuǎn)化成整數(shù),這樣才能和1作比較。
在絕大多數(shù)情況下對于事務都需要采用手工事務的方式來確保事務的正確性和事務時間的有效性。
思考題:
對于Discuz論壇來說如何做一個有效的用戶注冊腳本通過手工事務并且獲得準確注冊操作的響應時間。
業(yè)務分析:
注冊用戶后,在系統(tǒng)的頁面上會出現(xiàn)【歡迎:注冊用戶名】的信息,可以在注冊后返回的頁面中檢查是否出現(xiàn)了這樣的內(nèi)容來判斷注冊事務是否成功。
通過檢查頁面可以得到需要判斷的代碼為:
歡迎:<a class="dropmenu" id="viewpro" onmouseover="showMenu(this.id)">
所以在檢查點函數(shù)中需要添加這個內(nèi)容,為了更好地判斷,還需要把注冊用戶的名字也加進去,最后可以得到下面的代碼:
Action()
{
web_url("注冊",
"URL=http://192.168.0.200/register.aspx",
"TargetFrame=",
"Resource=0",
"RecContentType=text/html",
"Referer=http://192.168.0.200/",
"Snapshot=t2.inf",
"Mode=HTML",
EXTRARES,
"URL=/templates/default/images/check_error.gif", ENDITEM,
"URL=/templates/default/images/check_right.gif", ENDITEM,
"URL=/images/level/3.gif", ENDITEM,
LAST);
lr_start_transaction("reg");
web_reg_find("Search=Body",
"SaveCount=regst",
"Text=歡迎:<a class=\"dropmenu\" id=\"viewpro\" onmouseover= \"showMenu(this.id)\">{username}",
LAST);
web_submit_data("register.aspx",
"Action=http://192.168.0.200/register.aspx?createuser=1",
"Method=POST",
"TargetFrame=",
"RecContentType=text/html",
"Referer=http://192.168.0.200/register.aspx",
"Snapshot=t11.inf",
"Mode=HTML",
ITEMDATA,
"Name=username", "Value={username}", ENDITEM,
"Name=password", "Value=112212", ENDITEM,
"Name=password2", "Value=112212", ENDITEM,
"Name=email", "Value={username}@cloud.chen", ENDITEM,
"Name=submit", "Value=創(chuàng)建用戶", ENDITEM,
"Name=question", "Value=0", ENDITEM,
"Name=answer", "Value=", ENDITEM,
"Name=realname", "Value=", ENDITEM,
"Name=idcard", "Value=", ENDITEM,
"Name=mobile", "Value=", ENDITEM,
"Name=phone", "Value=", ENDITEM,
"Name=gender", "Value=0", ENDITEM,
"Name=nickname", "Value=", ENDITEM,
"Name=bday_y", "Value=", ENDITEM,
"Name=bday_m", "Value=", ENDITEM,
"Name=bday_d", "Value=", ENDITEM,
"Name=location", "Value=", ENDITEM,
"Name=msn", "Value=", ENDITEM,
"Name=yahoo", "Value=", ENDITEM,
"Name=skype", "Value=", ENDITEM,
"Name=icq", "Value=", ENDITEM,
"Name=qq", "Value=", ENDITEM,
"Name=homepage", "Value=", ENDITEM,
"Name=bio", "Value=", ENDITEM,
"Name=templateid", "Value=0", ENDITEM,
"Name=tpp", "Value=0", ENDITEM,
"Name=ppp", "Value=0", ENDITEM,
"Name=newpm", "Value=radiobutton", ENDITEM,
"Name=pmsound", "Value=1", ENDITEM,
"Name=showemail", "Value=1", ENDITEM,
"Name=receivesetting", "Value=2", ENDITEM,
"Name=receivesetting", "Value=4", ENDITEM,
"Name=invisible", "Value=0", ENDITEM,
"Name=signature", "Value=", ENDITEM,
"Name=sigstatus", "Value=1", ENDITEM,
LAST);
if(atoi(lr_eval_string("{regst}"))>=1)
lr_end_transaction("reg", LR_PASS);
else
lr_end_transaction("reg",LR_FAIL);
return 0;
}
這里的{username}是一個參數(shù),用來存放注冊的用戶名,在參數(shù)列表中設置了該參數(shù)的取值方式和信息。