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:\LR\baidu_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;
}
复制代码

 

 

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
lr_get_transaction_wasted_time函数<br>http://luochunfeng163.blog.163.com/blog/static/16700924920128205233959/<br>
 
 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.

 

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
初识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:\LR\baidu_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协议可以演示出来

 

posted @   Agoly  阅读(2108)  评论(1编辑  收藏  举报
点击右上角即可分享
微信分享提示