lr_start_timer，lr_get_transaction_duration，lr_get_transaction_wasted_time函數使用總結

lr_start_timer：

函數的功能：

爲了計算時間更加精確，能夠用這個函數去掉LR自身的檢查點所浪費的時間。如text check and image time

 

Action()
{
double time_elapsed;
merc_timer_handle_t timer;

web_url("487989.html",
   "URL=http://www.cnblogs.com/tester2test/archive/2006/08/28/487989.html",
   "Resource=0",
   "RecContentType=text/html",
   "Referer=",
   "Snapshot=t2.inf",
   "Mode=HTML",
   LAST);

lr_start_transaction("download");

timer = lr_start_timer();

Download("http://files.cnblogs.com/tester2test/xncssj.pdf", "http://www.cnblogs.com/tester2test/archive/2006/08/28/487989.html", "c:\\test.pdf", "wb");

time_elapsed = lr_end_timer(timer);

lr_wasted_time(time_elapsed * 1000);

lr_end_transaction("download", LR_AUTO);

return 0;
}

 

double time_elapsed, duration, waste;

merc_timer_handle_t timer;

        lr_start_transaction("sampleTrans");

        web_url("index.htm",

               "URL=http://localhost/index.htm",

               "TargetFrame=",

               "Resource=0",

               "RecContentType=text/html",

               "Referer=",

               "Snapshot=t1.inf",

               "Mode=HTML",

               LAST);

        timer = lr_start_timer();

/* Do some checks the duration of which

is not to be included in the transaction. */

        web_image_check("ImgCheck1",

               "src=index_files/image002.jpg",

               LAST);

        web_image_check("ImgCheck2",

               "src=index_files/planets.gif",

               LAST);

// How long did the tests take in seconds.

        time_elapsed = lr_end_timer(timer);

// Convert to millisecond.s

        waste = time_elapsed * 1000;

/* Remove the time the checks took from

        the transaction. */

        lr_wasted_time(waste);

         lr_end_transaction("sampleTrans", LR_AUTO);

 

 

lr_get_transaction_duration：返回事件執行到此處所用的時間

C 語言:

double lr_get_transaction_duration(const char *transaction);

   
Example:

Action()

{

      double Connect_trans_time;  // 接收函數返回值

      double Move_trans_time;

   

      lr_start_transaction("Connect_trans");

      lr_create_socket("socket0","TCP","RemoteHost = localhost:1111",LrsLastArg);  // IP和端口僅供參考

      //......(others)

   

      // 調用 lr_get_transaction_duration() 函數

      Connect_trans_time = lr_get_transaction_duration("Connect_trans");

      lr_end_transaction("Connect_trans",LR_AUTO);

   

      lr_start_transaction("Move_trans");

      //......(others)

      Move_trans_time = lr_get_transaction_duration("Move"); // 獲取 Move_trans 事件執行到此處所用時間

      lr_end_transaction("Move_trans",LR_AUTO);

   

      lr_output_message("The duration up to the <Connect_trans_time> is %f seconds",Connect_trans_time);

      lr_output_message("The duration up to the <Move_trans_time> is %f seconds",Move_trans_time);

   

      return 0;

}

    

   

Action.c(1259): Notify: Transaction "Connect_trans" ended with "Pass" status (Duration:1.1164)

Action.c(1717): Notify: Transaction "Move_trans" ended with "Pass" status (Duration: 0.4036)

Action.c(1719): The duration up to the <Connec_trans_time> is 1.116110 seconds

Action.c(1721): The duration up to the <Move_trans_time> is 0.403350 seconds

    

根據業務操做分離出腳本中的兩個事件，Connect（鏈接DB）操做和Move（拖屏）操做，Contro中運行結果顯示「拖屏」消耗時間遠大於「鏈接」消耗時間，這同程序設計與實現的實際狀況不符。

因此調用了【lr_get_transaction_duration();】函數來驗證事件的運行時間，進一步分析性能問題緣由所在。

驗證結果已證實拖屏操做消耗時間的確小於鏈接操做消耗時間。

 

lr_get_transaction_wasted_time：函數用於返回指定事物當前的損耗時間(wasted time)。

函數統計的是事物開始到此函數位置，lr自身的浪費時間（如：執行關聯、檢查點等函數的時間）。
 
損耗時間一般是指腳本消耗在爲了支持測試分析而作的操做時間。這些操做不會被實際用戶所執行。
 
例如一些循環賦值操做或插入檢查點操做。消耗的時間有lr_wasted_time函數在

 
lr_get_transaction_wasted_time函數以前移除了，移除後才獲得對應的結果。

函數語法結果

double lr_get_transaction_wasted_time （const char * transaction);

參數 transaction 爲事物名稱

 
使用lr_get_transaction_wansted_time
函數必須注意，

一它只能對當前運行狀態的事物才能返回大於等於0的結果，不然返回小於0的結果。

二是他使用以前應調用lr_wansted_time 函數移除過損耗時間
wasted time，不然lr_get_transaction_wansted_time將返回0。

 

附代碼以下：
        timer=lr_start_timer();
         web_find("web_find",
         "what=9000000022",
         LAST);
         time_elapsed=lr_end_timer(timer);

         lr_output_message("find時間爲：%f",time_elapsed);
         lr_output_message("事務當前的損耗時間爲：%f",lr_get_transaction_wasted_time("登錄"));  //先算出從事務開始到如今lr自身的浪費時間。由於無損耗,因此，lr_get_transaction_wasted_time= 0s 。

        //使用lr_wasted_time（）函數爲事物添加浪費時間
        lr_wasted_time(time_elapsed*1000);     //Wasted Time=lr自身的浪費時間（0s）+第三方時間的開銷（time_elapsed*1000s)）
        lr_output_message("find時間爲：%f,事務當前的損耗時間爲：%f",time_elapsed,lr_get_transaction_wasted_time("登錄"));

 

 

Action()
{
    int i, baseIter = 1000; 


    char dude[1000]; 


    double wasteTime, actualElapsedTime; 


    merc_timer_handle_t MasterT, timer; 


    // Examine the total elapsed time of the action 


    MasterT = lr_start_timer(); 


    //Start transaction 


    lr_start_transaction("Demo"); 


    // Create some elapsed time for the transaction 


    for (i=0; i< (10 * baseIter); ++i) 
        sprintf(dude, "This is the way we create elapsed time artificially = %d", i); 
    


    // Add some think time 


    lr_think_time(0.5); 


    // Create some wasted time and record it with timer 


    timer = lr_start_timer(); 


    for (i=0; i< (5 * baseIter); ++i) 


  sprintf(dude, "This is the way we waste time in a script = %d", i); 


    wasteTime = lr_end_timer(timer); 


    lr_output_message("User created waste time = %lf", wasteTime); 


    lr_output_message("Before lr_waste_time: Duration = %lf - Waste = %lf",         


        lr_get_transaction_duration("Demo"), 


        lr_get_transaction_wasted_time("Demo")); 


    /* Convert Timer in seconds to wasted time in milliseconds 


     and add to internally generated waste time */ 


    wasteTime *= 1000; 


    lr_wasted_time(wasteTime); 


    lr_output_message("After lr_waste_time: Duration = %lf - Waste = %lf", 


            lr_get_transaction_duration("Demo"), 


            lr_get_transaction_wasted_time("Demo")); 


    lr_output_message("Think time = %lf", lr_get_transaction_think_time("Demo")); 


    lr_end_transaction("Demo", LR_AUTO); 


    actualElapsedTime = lr_end_timer(MasterT); 


    lr_output_message("Total Elapsed time for Action = %lf", actualElapsedTime);




 return 0;
}


結果：
Starting iteration 1.
Starting action Action.
Action.c(17): Notify: Transaction "Demo" started.
Action.c(45): User created waste time = 15.768059
Action.c(47): Before lr_waste_time: Duration = 65.147478 - Waste = 0.000000
Action.c(61): After lr_waste_time: Duration = 65.153110 - Waste = 15.768000
Action.c(67): Think time = 0.000000
Action.c(71): Notify: Transaction "Demo" ended with "Pass" status (Duration: 65.1589 Wasted Time: 15.7680).
Action.c(75): Total Elapsed time for Action = 65.170579
Ending action Action.
Ending iteration 1.

 

 

 lr_get_transaction_wasted_time函數用於返回指定事物當前的損耗時間(wasted time)。     損耗時間一般是指腳本消耗在爲了支持測試分析而作的操做時間。這些操做不會被實際用戶所執行。     例如一些循環賦值操做或插入檢查點操做。消耗的時間有lr_wasted_time函數在
  lr_get_transaction_wasted_time函數以前移除了，移除後才獲得對應的結果。
  函數語法結果
  double lr_get_transaction_wasted_time （const char * transaction);
  參數 transaction 爲事物名稱
  使用lr_get_transaction_wansted_time 函數必須注意，一它只能對當前運行狀態的事物才能返回大於等於0的結果，不然返回小於0的結果。二是他使用以前應調用lr_wansted_time 函數移除過損耗時間 wasted time，不然lr_get_transaction_wansted_time將返回0。

幫助例子程序：

WasteTime()

{

       int i, baseIter = 1000;

       char dude[1000];

       double wasteTime, actualElapsedTime;

       merc_timer_handle_t MasterT, timer;

       // Examine the total elapsed time of the action

       MasterT = lr_start_timer();

       //Start transaction

       lr_start_transaction("Demo");

       // Create some elapsed time for the transaction

       for (i=0; i< (10 * baseIter); ++i)

      sprintf(dude,

        "This is the way we create elapsed  time artificially = %d", i);                 

       // Add some think time

       lr_think_time(0.5);

       // Create some wasted time and record it with timer

       timer =lr_start_timer();

       for (i=0; i< (5 * baseIter); ++i)

                     sprintf(dude,

                            "This is the way we waste time in  a script. = %d", i);

       wasteTime =lr_end_timer(timer);

       lr_output_message("User created waste time = %lf",  wasteTime);

       lr_output_message("Before lr_waste_time: Duration = %lf  - Waste = %lf",              

         lr_get_transaction_duration("Demo"),

        lr_get_transaction_wasted_time("Demo"));

       /* Convert Timer in seconds to wasted time in  milliseconds

        and add to internally generated waste time */

       wasteTime *= 1000;

       lr_wasted_time(wasteTime);

       lr_output_message("After lr_waste_time: Duration = %lf  - Waste = %lf",

        lr_get_transaction_duration("Demo"),

       lr_get_transaction_wasted_time("Demo"));

       lr_output_message("Think time = %lf",

              lr_get_transaction_think_time("Demo"));

       lr_end_transaction("Demo", LR_AUTO);

       actualElapsedTime = lr_end_timer(MasterT);

       lr_output_message("Total Elapsed time for Action =  %lf",

              actualElapsedTime);

       return 0;

}

Vuser Output log file 輸出日誌

Note there is no difference between the transaction duration  before and after the call to lr_waste_time

WasteTime.c(28): User created waste time = 0.031250       

WasteTime.c(32): Before lr_waste_time: Duration = 0.609375 -  Waste = 0.000000       

WasteTime.c(40): After lr_waste_time: Duration = 0.625000 -  Waste = 0.031000       

WasteTime.c(44): Think time = 0.500000       

WasteTime.c(47): Notify: Transaction Demo ended with Pass  status (Duration: 0.6406 Think Time: 0.5000 Wasted Time: 0.0310).       

WasteTime.c(50): Total Elapsed time for Action = 0.640625        

Analysis: Average Response Time Raw Data

Note that the Transaction Response Time for "Demo" is 0.61.  This is the Duration from the Vuser log (0.6406) minus the Wasted Time (  0.0310).

Transaction End Status	Transaction Father Tree path	Scenario Elapsed Time	Transaction Response Time	Transaction Name
Pass	NONE	4.843	0	vuser_init_Transaction
Pass	WasteTime_Transaction	5.514	0.61	Demo
Pass	NONE	5.53	0.625	WasteTime_Transaction
Pass	NONE	5.53	0	vuser_end_Transaction