事务时间如何去掉wasted time
一个事务的时间是指持续时间,事务会完全记录下从事务开始到事务结束之间的时间差,那么事务的时间能真实地反映业务操作的时间吗?不能,就好像人用手按秒表来记录短跑时间一样,得出的时间并不是完全准确,存在观察的误差和操作的误差,对于一个事务时间来说,一般由四部分组成,如图3.166所示。
图3.166 事务时间组成 |
响应时间
这是事务的目的,通过事务记录业务操作所消耗的响应时间。
事务自身时间
事务中哪怕没有操作,也是需要时间的,不过这个时间一般在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()函数实现。在函数内写入对应的时间(单位是秒),当脚本在Controller中运行到该函数时就会等待相应的时间。注意在VuGen中,回放Think Time默认关闭。
Think Time在进行性能测试的时候需要打开,只有这样每个虚拟用户才是真正按照用户的操作速度来完成请求,才能得到在真实情况下的系统数据。如果不打开Think Time,测试获得的数据是在全负载下的一些理论峰值数据。
那么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 会被算在事务的时间内,不过在Analysis中可以设置过滤规则将其扣除,另外我们也建议尽量不要在事务内使用lr_think_time()函数。
浪费时间(Wasted Time)
在使用事务的时候,经常会看到在事务日志中有Wasted Time。Wasted Time是指事务中应该扣除的由于其他原因导致的时间浪费。在默认情况下LoadRunner会将自身脚本运行浪费的时间自动记入Wasted Time。例如执行关联、检查点等函数的时间。
除了脚本自身浪费的时间,某些时候使用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自带的时间计数器,它和lr_end_timer()相对应,能够返回这两个函数间的时间差。
运行脚本后,等待一段时间脚本运行结束,可以看到以下日志。
- 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时间内,导致Transaction的时间变长。当通过lr_start_timer()计时函数将这个消耗时间加入Wasted Time后,这个脚本就能正确地计算出事务的时间和该事务时间的Wasted Time了。当在场景中运行的时候,事务的响应时间会自动扣除Wasted Time。
为了确保响应时间的正确,需要扣除在运行脚本时自身的时间消耗,事务中尽量避免出现非请求的处理内容,如果无法避免请使用lr_wasted_time()函数将多余的时间开销扣除。
例如这样的脚本:
- merc_timer_handle_t timer; //变量声明
- lr_start_transaction("Demo");
- timer=lr_start_timer();
- lr_load_dll("getkey.dll");
- lr_save_string(getrandkey(),"key");
- //通过调用dll获得密钥
- wasteTime=lr_end_timer(timer);
- lr_wasted_time(wasteTime*1000);
- lr_end_transaction("Demo", LR_AUTO);
计算密钥是很消耗时间的,那么可以使用timer这个变量来记录计算的时间,并将这个时间从整个事务中扣除。
在计算Wasted Time时不要直接使用lr_wasted_time()覆盖,而忘了加上脚本中LoadRunner函数的自身时间。通过lr_get_transaction_wasted_time()函数可以获得事务自身的Wasted Time,将这个时间累加上第三方统计的Wasted Time再通过lr_wasted_time()函数覆盖。