LoadRunner去除事物中的程序的执行时间

大家在性能测试过程中，经常会用到程序处理或组织数据，以达到一定的测试目的，但是程序本身执行会消耗一些时间，这部分消耗的时间是包含在响应时间里面，此时，响应时间=正常响应时间+程序执行消耗时间。那么如何来保证响应最接近真实，LoadRunner提供了一组函数，减去程序消耗时间，达到测试目的。函数（绿色标注）如下：

 

 double time_elapsed = 0.00, duration = 0.00, waste = 0.00,trans_time = 0.00,waste_time = 0.00; 

 merc_timer_handle_t timer; 

         timer = lr_start_timer(); //timer开始

 

         if(strlen(lr_eval_string("{P_Bal}")) > 0)

         {

           for(i=0;i < strlen(lr_eval_string("{P_Bal}"));i++)

                   {

                            //lr_error_message("%d",i);

                            lr_save_var(lr_eval_string("{P_Bal}")+i,1,0,"P_Value");

                            #define temp = 0;

                            //lr_error_message("%s",lr_eval_string("{P_Value}"));

                            if(atoi(lr_eval_string("{P_Value}")) != 0)

                           {

                                     if(strcmp(lr_eval_string("{P_Value}"),",") != 0 && strcmp(lr_eval_string("{P_Value}"),".") != 0)

                                     {

                                               break;

                                     }

                            }

                   }

         }

 

         time_elapsed = lr_end_timer(timer);//停止timer

         lr_output_message("%lf",time_elapsed);

 

waste = time_elapsed * 1000; //毫秒转成秒

 

         if(lr_get_transaction_status("XXX") == 1 || atoi(lr_eval_string("{P_Value}")) <= 0)

         {

lr_wasted_time(waste);//响应时间减去纯语句消耗的时间

         lr_end_transaction("XXX", LR_FAIL);

                    lr_output_message("XXX失败 %s %s",lr_eval_string("{UserName}"),lr_eval_string("{P_AccountId}"));

         goto exit;

         }

以下代码：

    由于web_find函数进行的操作无须包括在事务总执行时间中，因些要用计时器来计算其执行时间，然后用lr_wasted_time函数将其从事务的总执行时间中扣除。

Action()

{

    double time_elapsed;

    merc_timer_handle_t timer;




    lr_start_transaction("Search");

    web_url("baidu_search",

            "url=http://www.baidu.com/s?wd=LoadRunner",

            "mode=html",

            LAST);

    timer=lr_start_timer();//创建计时器，返回值是计时器标志




    web_find("web_find","what=load",LAST);




    time_elapsed=lr_end_timer(timer);//计时结束，计时结果time_elapsed返回值单位是秒




    lr_wasted_time(time_elapsed*1000);//lr_wasted_time函数定义的参数是毫秒，所以要*1000




    lr_error_message("Find Time= %lf,wasted_time=%lf",time_elapsed,lr_get_transaction_wasted_time("Search"));

    lr_end_transaction("Search",LR_AUTO);

    return 0;

}

以上代码，lr_get_transaction_wasted_time使用注意点：

1、要在lr_end_transaction之前使用，因为它只能对当前处于“运行状态”的事务返回>0的结果。

2、调用lr_get_transaction_wasted_time之前，要使用lr_wasted_time移除损耗时间。

关于时间的几个函数：
lr_get_transaction_duration得到transaction运行到当前位置的duration，包含事务的响应时间和wasted time，单位是s;

着重理解下wasted time:
 wasted time包括事务中函数自身执行所消耗的时间，这个时间是loadrunner自动会计的，计在lr_get_transaction_wasted_time里面，还有比如C语言等外部接口进行处理的时间这个loadrunner不会自动计，但是我们可以通过lr_start_timer（单位是s）、lr_end_timer（单位是s）、lr_wasted_time（这个函数的形参中wasted time的单位是毫秒，所以通过timer计的时间需要乘上1000）等函数手动计入lr_get_transaction_wasted_time里面

 下面来验证下：
Action()
 {
     int i, baseIter = 200; 
     char dude[200]; 
     double wasteTime; 
     merc_timer_handle_t timer; 

     lr_start_transaction("baidu");

     web_add_cookie("BAIDUID=63CCB143FE1734437DBED1D457D18E3E:FG=1; DOMAIN=www.baidu.com");

     web_add_cookie("BAIDUID=63CCB143FE1734437DBED1D457D18E3E:FG=1; DOMAIN=passport.baidu.com");

     web_add_cookie("BAIDUID=63CCB143FE1734437DBED1D457D18E3E:FG=1; DOMAIN=suggestion.baidu.com");

 web_url("www.baidu.com", 
 "URL=http://www.baidu.com/", 
 "Resource=0", 
 "RecContentType=text/html", 
 "Referer=", 
 "Snapshot=t1.inf", 
 "Mode=HTML", 
 EXTRARES, 
 "Url=http://s1.bdstatic.com/r/www/cache/static/global/img/icons_37d13939.png", ENDITEM, 
 "Url=http://s1.bdstatic.com/r/www/cache/static/sug/js/bdsug_31b8d653.js", ENDITEM, 
 "Url=/favicon.ico", "Referer=", ENDITEM, 
 "Url=http://passport.baidu.com/passApi/js/uni_login_wrapper.js?cdnversion=1400118095796&_=1400118095656", ENDITEM, 
 "Url=http://suggestion.baidu.com/su?
 wd=&zxmode=1&json=1&p=3&sid=4948_6429_1450_5223_6505_4760_6017_6462_6428_6456_6454&cb=jQuery110208749060739643981_1400118095657&_=1400118095658", ENDITEM, LAST);

 //在脚本中间位置，记录此时事务自身函数消耗的时间，这个是loadrunner自动计的
    lr_output_message("User created waste time to this point calculated by loadrunner = %lf", lr_get_transaction_wasted_time("baidu")); 

 //使用一个测试语句手动记录消耗的时间
    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 calculated by timer = %lf", wasteTime); 

     wasteTime *= 1000; 

 //通过lr_wasted_time函数将wasteTime标记为wasted time
     lr_wasted_time(wasteTime); 

 //通过lr_get_transaction_wasted_time函数会汇总手工记录的消耗时间和loadrunner自动记录的消耗时间
    lr_output_message("Total User created waste time = %lf", lr_get_transaction_wasted_time("baidu")); 

     lr_output_message("Transaction duration = %lf", lr_get_transaction_duration("baidu")); 

     lr_end_transaction("baidu", LR_AUTO);

     return 0;
 }

运行日志如下：
Virtual User Script started at : 2014-05-15 09:58:45
 Starting action vuser_init.
 Web Turbo Replay of LoadRunner 11.0.0 for WINXP; build 8859 (Aug 18 2010 20:14:31)   [MsgId: MMSG-27143]
 Run Mode: HTML   [MsgId: MMSG-26000]
 Run-Time Settings file: "F:LRaidu_open\default.cfg"   [MsgId: MMSG-27141]
 Ending action vuser_init.
 Running Vuser...
 Starting iteration 1.
 Starting action Action.
 Action.c(12): Notify: Transaction "baidu" started.
 Action.c(14): web_add_cookie was successful   [MsgId: MMSG-26392]
 Action.c(16): web_add_cookie was successful   [MsgId: MMSG-26392]
 Action.c(18): web_add_cookie was successful   [MsgId: MMSG-26392]
 Action.c(20): Downloading resource "http://s1.bdstatic.com/r/www/cache/static/global/img/icons_37d13939.png" (specified by argument number 9)   [MsgId: MMSG-26577]
 Action.c(20): Downloading resource "http://s1.bdstatic.com/r/www/cache/static/sug/js/bdsug_31b8d653.js" (specified by argument number 11)   
 [MsgId: MMSG-26577]
 Action.c(20): Downloading resource "http://www.baidu.com/favicon.ico" (specified by argument number 13)   [MsgId: MMSG-26577]
 Action.c(20): Downloading resource "http://passport.baidu.com/passApi/js/uni_login_wrapper.js?cdnversion=1400118095796&_=1400118095656" (specified by argument number 16)   [MsgId: MMSG-26577]
 Action.c(20): Downloading resource "http://suggestion.baidu.com/su?wd=&zxmode=1&json=1&p=3&sid=4948_6429_1450_5223_6505_4760_6017_6462_6428_6456_6454&cb=jQuery110208749060739643981_1400118095657&_=1400118095658" (specified by argument number 18)   [MsgId: MMSG-26577]
 Action.c(20): Found resource "http://www.baidu.com/img/baidu_jgylogo3.gif" in HTML "http://www.baidu.com/"   [MsgId: MMSG-26659]
 Action.c(20): Found resource "http://www.baidu.com/img/bdlogo.gif" in HTML "http://www.baidu.com/"   [MsgId: MMSG-26659]
 Action.c(20): Found resource "http://www.baidu.com/cache/global/img/gs-2.0.gif" in HTML "http://www.baidu.com/"   [MsgId: MMSG-26659]
 Action.c(20): Found resource "http://s1.bdstatic.com/r/www/cache/static/jquery/jquery-1.10.2.min_f2fb5194.js" in HTML "http://www.baidu.com/"   [MsgId: MMSG-26659]
 Action.c(20): Found resource "http://s1.bdstatic.com/r/www/cache/static/global/js/all_async_f712ea4c.js" in HTML "http://www.baidu.com/"   [MsgId: MMSG-26659]
 Action.c(20): Found resource "http://s1.bdstatic.com/r/www/cache/static/global/js/imsg_45172630.js" in HTML "http://www.baidu.com/"   [MsgId: MMSG-26659]
 Action.c(20): web_url("www.baidu.com") was successful, 106231 body bytes, 4084 header bytes, 59 chunking overhead bytes   [MsgId: MMSG-26385]
 Action.c(35): User created waste time to this point calculated by loadrunner = 0.758138
 Action.c(45): User created waste time calculated by timer = 7.646098
 Action.c(52): Total User created waste time = 8.404138
 Action.c(53): Transaction duration = 8.745259
 Action.c(55): Notify: Transaction "baidu" ended with "Pass" status (Duration: 8.7524 Wasted Time: 8.4041).
 Ending action Action.
 Ending iteration 1.
 Ending Vuser...
 Starting action vuser_end.
 Ending action vuser_end.
 Vuser Terminated.
运行的结果也证明了我之前的理解

 注：在最开始的时候，使用oracle两层协议录制脚本，一直不能演示出自身函数消耗的时间，lr_get_transaction_wasted_time的值都为0，后来使用http协议可以演示出来

Action()
{
int i=0;
int j=0;
int l;

double time_elapsed, duration, waste; 
merc_timer_handle_t timer; 
for (l=1;l<=100;l++) {
lr_start_transaction("测试");
timer = lr_start_timer(); 
//lr_think_time(4);
time_elapsed = lr_end_timer(timer); 


// Convert to millisecond.s 
waste = time_elapsed * 1000; 



if(waste>2)

{
lr_end_transaction("测试", LR_FAIL);
lr_output_message("时间= %f",waste);        

i=i+1;
}
else

{
lr_end_transaction("测试", LR_PASS);
lr_output_message("时间= %f",waste);

j=j+1;
};

};

lr_output_message("成功次数为= %d",j);
lr_output_message("失败次数为= %d",i);

        return 0;
}

lr_get_transaction_wasted_time函数
http://luochunfeng163.blog.163.com/blog/static/16700924920128205233959/


 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。


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.

初识loadrunner wasted time




关于时间的几个函数：
lr_get_transaction_duration得到transaction运行到当前位置的duration，包含事务的响应时间和wasted time，单位是s;

着重理解下wasted time:
 wasted time包括事务中函数自身执行所消耗的时间，这个时间是loadrunner自动会计的，计在lr_get_transaction_wasted_time里面，还有比如C语言等外部接口进行处理的时间这个loadrunner不会自动计，但是我们可以通过lr_start_timer（单位是s）、lr_end_timer（单位是s）、lr_wasted_time（这个函数的形参中wasted time的单位是毫秒，所以通过timer计的时间需要乘上1000）等函数手动计入lr_get_transaction_wasted_time里面

 下面来验证下：
Action()
 {
     int i, baseIter = 200; 
     char dude[200]; 
     double wasteTime; 
     merc_timer_handle_t timer; 

     lr_start_transaction("baidu");

     web_add_cookie("BAIDUID=63CCB143FE1734437DBED1D457D18E3E:FG=1; DOMAIN=www.baidu.com");

     web_add_cookie("BAIDUID=63CCB143FE1734437DBED1D457D18E3E:FG=1; DOMAIN=passport.baidu.com");

     web_add_cookie("BAIDUID=63CCB143FE1734437DBED1D457D18E3E:FG=1; DOMAIN=suggestion.baidu.com");

 web_url("www.baidu.com", 
 "URL=http://www.baidu.com/", 
 "Resource=0", 
 "RecContentType=text/html", 
 "Referer=", 
 "Snapshot=t1.inf", 
 "Mode=HTML", 
 EXTRARES, 
 "Url=http://s1.bdstatic.com/r/www/cache/static/global/img/icons_37d13939.png", ENDITEM, 
 "Url=http://s1.bdstatic.com/r/www/cache/static/sug/js/bdsug_31b8d653.js", ENDITEM, 
 "Url=/favicon.ico", "Referer=", ENDITEM, 
 "Url=http://passport.baidu.com/passApi/js/uni_login_wrapper.js?cdnversion=1400118095796&_=1400118095656", ENDITEM, 
 "Url=http://suggestion.baidu.com/su?
 wd=&zxmode=1&json=1&p=3&sid=4948_6429_1450_5223_6505_4760_6017_6462_6428_6456_6454&cb=jQuery110208749060739643981_1400118095657&_=1400118095658", ENDITEM, LAST);

 //在脚本中间位置，记录此时事务自身函数消耗的时间，这个是loadrunner自动计的
    lr_output_message("User created waste time to this point calculated by loadrunner = %lf", lr_get_transaction_wasted_time("baidu")); 

 //使用一个测试语句手动记录消耗的时间
    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 calculated by timer = %lf", wasteTime); 

     wasteTime *= 1000; 

 //通过lr_wasted_time函数将wasteTime标记为wasted time
     lr_wasted_time(wasteTime); 

 //通过lr_get_transaction_wasted_time函数会汇总手工记录的消耗时间和loadrunner自动记录的消耗时间
    lr_output_message("Total User created waste time = %lf", lr_get_transaction_wasted_time("baidu")); 

     lr_output_message("Transaction duration = %lf", lr_get_transaction_duration("baidu")); 

     lr_end_transaction("baidu", LR_AUTO);

     return 0;
 }

运行日志如下：
Virtual User Script started at : 2014-05-15 09:58:45
 Starting action vuser_init.
 Web Turbo Replay of LoadRunner 11.0.0 for WINXP; build 8859 (Aug 18 2010 20:14:31)   [MsgId: MMSG-27143]
 Run Mode: HTML   [MsgId: MMSG-26000]
 Run-Time Settings file: "F:LRaidu_open\default.cfg"   [MsgId: MMSG-27141]
 Ending action vuser_init.
 Running Vuser...
 Starting iteration 1.
 Starting action Action.
 Action.c(12): Notify: Transaction "baidu" started.
 Action.c(14): web_add_cookie was successful   [MsgId: MMSG-26392]
 Action.c(16): web_add_cookie was successful   [MsgId: MMSG-26392]
 Action.c(18): web_add_cookie was successful   [MsgId: MMSG-26392]
 Action.c(20): Downloading resource "http://s1.bdstatic.com/r/www/cache/static/global/img/icons_37d13939.png" (specified by argument number 9)   [MsgId: MMSG-26577]
 Action.c(20): Downloading resource "http://s1.bdstatic.com/r/www/cache/static/sug/js/bdsug_31b8d653.js" (specified by argument number 11)   
 [MsgId: MMSG-26577]
 Action.c(20): Downloading resource "http://www.baidu.com/favicon.ico" (specified by argument number 13)   [MsgId: MMSG-26577]
 Action.c(20): Downloading resource "http://passport.baidu.com/passApi/js/uni_login_wrapper.js?cdnversion=1400118095796&_=1400118095656" (specified by argument number 16)   [MsgId: MMSG-26577]
 Action.c(20): Downloading resource "http://suggestion.baidu.com/su?wd=&zxmode=1&json=1&p=3&sid=4948_6429_1450_5223_6505_4760_6017_6462_6428_6456_6454&cb=jQuery110208749060739643981_1400118095657&_=1400118095658" (specified by argument number 18)   [MsgId: MMSG-26577]
 Action.c(20): Found resource "http://www.baidu.com/img/baidu_jgylogo3.gif" in HTML "http://www.baidu.com/"   [MsgId: MMSG-26659]
 Action.c(20): Found resource "http://www.baidu.com/img/bdlogo.gif" in HTML "http://www.baidu.com/"   [MsgId: MMSG-26659]
 Action.c(20): Found resource "http://www.baidu.com/cache/global/img/gs-2.0.gif" in HTML "http://www.baidu.com/"   [MsgId: MMSG-26659]
 Action.c(20): Found resource "http://s1.bdstatic.com/r/www/cache/static/jquery/jquery-1.10.2.min_f2fb5194.js" in HTML "http://www.baidu.com/"   [MsgId: MMSG-26659]
 Action.c(20): Found resource "http://s1.bdstatic.com/r/www/cache/static/global/js/all_async_f712ea4c.js" in HTML "http://www.baidu.com/"   [MsgId: MMSG-26659]
 Action.c(20): Found resource "http://s1.bdstatic.com/r/www/cache/static/global/js/imsg_45172630.js" in HTML "http://www.baidu.com/"   [MsgId: MMSG-26659]
 Action.c(20): web_url("www.baidu.com") was successful, 106231 body bytes, 4084 header bytes, 59 chunking overhead bytes   [MsgId: MMSG-26385]
 Action.c(35): User created waste time to this point calculated by loadrunner = 0.758138
 Action.c(45): User created waste time calculated by timer = 7.646098
 Action.c(52): Total User created waste time = 8.404138
 Action.c(53): Transaction duration = 8.745259
 Action.c(55): Notify: Transaction "baidu" ended with "Pass" status (Duration: 8.7524 Wasted Time: 8.4041).
 Ending action Action.
 Ending iteration 1.
 Ending Vuser...
 Starting action vuser_end.
 Ending action vuser_end.
 Vuser Terminated.
运行的结果也证明了我之前的理解

 注：在最开始的时候，使用oracle两层协议录制脚本，一直不能演示出自身函数消耗的时间，lr_get_transaction_wasted_time的值都为0，后来使用http协议可以演示出来