LoadRunner中响应时间与事物时间详解

1. 响应时间

事务是指用户在客户端做一种或多种业务所需要的操作集,通过事务函数可以标记完成该业务所需要的操作内容;另一方面事务可以用来统计用户操作的响应时间,事务响应时间是通过记录用户请求的开始时间和服务器返回内容到客户端时间的差值来计算用户操作响应时间的,如图1所示。

图1  事务响应时间计算方式

这里的响应时间不包含客户端GUI时间(例如浏览器解释页面所消耗的时间)。

前面说响应时间是用户请求发出和服务器返回之间的时间差,那么得到这个时间就够了吗?

例如:现在有一场跑步比赛。当比赛完成后,可以得到每位运动员跑完整个比赛所需要消耗的时间,现在需要分析谁的起跑好、谁的冲刺好,能分析出来吗?答案是不能,虽然得到了最重要的完成比赛的响应时间,但是这对分析和优化几乎没有作用,因为只知道了结果而不知道过程。跑步的时间是由起跑、中途、冲刺等时间组成的,如果想要进行分析优化,必须先了解各个阶段所花费的时间和速度以及各个运动员的优缺点。

对于软件来说,通过事务得到的系统响应时间也是由非常多的部分组成的,一般来说响应时间由网络时间、服务器处理时间、网络延迟三大部分组成。先来看看当一个客户端发出请求到服务器返回需要经历哪些路径,如图2所示。

LoadRunner中响应时间与事物时间详解

1.网络时间

客户端发出请求首先通过网络来到Web Server上(消耗时间为N1);然后Web Server将处理后的请求发送给App Server(消耗时间为N2);App Server将操作数据指令发送给Database (消耗时间为N3);Database服务器将查询结果数据发送回App Server(消耗时间为N4);App Server将处理后的页面发给Web Server(消耗时间为N5);最后Web Server将HTML转发到客户端(消耗时间为N6)。这里的Nx都是网络传输上的时间开销,没有计算业务处理所需要花费的时间。

2.服务器处理时间

另外一个方面还要考虑各个服务器处理所需要的时间WT、AT、DT。

3.网络延迟

除了上面两种时间开销以外,还要考虑网络延迟的问题。

所以最终的响应时间组成为:

响应时间 = 网络延迟时间 + WT+AT+DT +(N1+N2+N3)+(N4+N5+N6)+ WT+AT+DT

也可以简单认为响应时间由网络开销(前端)和服务器开销(后端)两大部分组成,如图3所示。

LoadRunner中响应时间与事物时间详解

那么这些消耗的时间都花在什么事情上了呢?影响网络的因素一般包括以下内容:

1.前端Network

DNS Lookup

Time to connect

Time to first buffer

Network Time

Download Time

SSL handshake

FTP authentication

Client Time

Error Time

网络延迟

2.后端服务

Web Server

Servlet Time

Method Time

静态动态压缩

App Server

EJB Time

Method Time

JNDI Lookup

Database Server

JDBC Time

Connect Time

Execute Time

这里会发现响应时间的组成是非常复杂的,当性能问题出现时,想要定位到具体的代码级别是相当困难的。

LoadRunner只能对自己发出的请求和服务器返回的内容进行网络级别的分析,也就是说LoadRunner能够分析的时间为客户到WWW服务器的时间N1和WWW服务器返回到客户的时间N6。这些时间主要和网络速度有关,可以用一个LoadRunner的名称来解释,叫做Web Page Breakdown。

也就是说VuGen可以分析的时间只有客户端到Web Server之间的部分,后面从Web Server到App Server再到Database Server的时间只能得到一个总和。

2.  事务时间

一个事务的时间是指持续时间,事务会完全记录下从事务开始到事务结束之间的时间差,那么事务的时间能真实地反映业务操作的时间吗?不能,就好像人用手按秒表来记录短跑时间一样,得出的时间并不是完全准确,存在观察的误差和操作的误差,对于一个事务时间来说,一般由四部分组成,如图4所示。

图4 事务时间组成

响应时间

这是事务的目的,通过事务记录业务操作所消耗的响应时间。

事务自身时间

事务中哪怕没有操作,也是需要时间的,不过这个时间一般在0.01秒左右,所以可以忽略。

1.     lr_start_transaction(“thinktime”);

2.     lr_end_transaction(“thinktime”, LR_AUTO);

运行上面的脚本后,可以看到:

1.     Action.c(5): Notify: Transaction “thinktime” started.

2.  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 在事务中如何影响事务时间呢?编写如下脚本:

1.     lr_start_transaction(“thinktime”);

2.     lr_think_time(5);

3.     lr_end_transaction(“thinktime”, LR_AUTO);

在Run-time Settings中设置Think Time,启用Replay Think Time功能,运行之后可以看到以下结果:

1.     Action.c(5): Notify: Transaction “thinktime” started.

2.     Action.c(7): lr_think_time: 5.00 seconds.

3.     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中。

运行一下下面的代码:

1.     Action()

2.     {

3.         int i;

4.         int baseIter = 100;

5.         char dude[1000];

6.         merc_timer_handle_t timer;

7.         // Examine the total elapsed time of the action

8.         //Start transaction

9.         lr_start_transaction(“Demo”);

10.        timer=lr_start_timer();

11.        for (i=0;i<=baseIter*1000;i++) {

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

13.               }

14.         wasteTime=lr_end_timer(timer); //时间单位为毫秒

15.        lr_wasted_time(wasteTime*1000);//将wasteTime转换为秒并计入lr的Wasted Time,当在场景中运行的时候,事务的响应时间会自动扣除Wasted Time

16.        lr_end_transaction(“Demo”, LR_AUTO);

17.        return 0;

18.    }

其中,lr_start_timer()是一个LoadRunner自带的时间计数器,它和lr_end_timer()相对应,能够返回这两个函数间的时间差。

运行脚本后,等待一段时间脚本运行结束,可以看到以下日志。

1.     Action.c(18): Notify: Transaction “Demo” started.

2.     Action.c(27): wasted time is 85.860000

3.     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()函数将多余的时间开销扣除。

例如这样的脚本:

1.     merc_timer_handle_t timer; //变量声明

2.     lr_start_transaction(“Demo”);

3.     timer=lr_start_timer();

4.     lr_load_dll(“getkey.dll”);

5.     lr_save_string(getrandkey(),”key”);

6.     //通过调用dll获得密钥

7.     wasteTime=lr_end_timer(timer);

8.     lr_wasted_time(wasteTime*1000);

9.     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()函数覆盖。

3.手工事务

前面都是使用LR_AUTO来自动判断事务状态,现在来做一个脚本,看看LoadRunner的事务是如何自动判断状态的。

录制一个论坛注册用户的脚本,在提交注册表单处添加事务开始及结束标志,然后回放该脚本。事务的结果是PASS还是FAIL呢?虽然回放脚本注册用户是失败的(该用户已经存在),但是事务还是在PASS状态下完成了,而且会发现事务的持续时间很短。正常情况下注册一个用户到刷新首页一般都要2秒,现在只需要0.3秒。这是因为当服务器判断到该用户已存在后,就没有了数据插入和等待1秒刷新首页的操作,而是直接返回错误提示页面。这个0.3秒是系统处理错误的时间而不是注册用户所需要的时间。

LR_AUTO也是根据服务器的返回状态信息来决定事务是以LR_PASS状态通过还是以LR_FAIL状态结束,只要服务器返回页面,那么事务就会认为请求成功发出去了,服务器看懂了请求也返回了内容,自然事务是PASS状态了。

这样由于事务自动判断的错误,导致虽然操作是失败的,但得到了一个响应时间,并且这个响应时间又没有正确反映出做这件事情的真正时间,最终就会影响到性能测试得到的数据。

记得在论坛上就有朋友问过这样的问题,为什么系统在用户越来越多的情况下,响应时间不增反减?这种现象很有可能就是没有使用手工事务导致的结果。

对于这种情况就需要手工来判断操作是否成功,通过web_reg_find()检查点函数来检查页面是否返回正确,然后通过rowcount的参数值来进行事务状态判断,做到智能判断事务结果。

例如:检查点函数的rowcount保存在参数loginst中,那么事务的状态就应该这样判断:

1.     lr_start_transaction(“login”);

2.     web_reg_find(“Search=Body”,

3.             “SaveCount=loginst”,

4.             “Text=登录失败”,

5.             LAST);

6.     //登录请求

7.     If(atoi(lr_eval_string(“{loginst}”))>=1))

8.             lr_end_transaction(“login”, LR_FAIL);

9.     else

10.            lr_end_transaction(“login”,LR_PASS);

通过检查点来检查登录后页面是不是存在”登录失败”这样的内容,如果存在那么loginst的值就大于等于1,然后把loginst的值取出来和1做比较,如果大于1那么就是登录失败,否则就是登录成功。

参数不能和值做比较,所以要先通过lr_eval_string()函数将其转化成字符串,然后再通过atoi()函数转化成整数,这样才能和1作比较。

在绝大多数情况下对于事务都需要采用手工事务的方式来确保事务的正确性和事务时间的有效性。

思考题:

对于Discuz论坛来说如何做一个有效的用户注册脚本通过手工事务并且获得准确注册操作的响应时间。

业务分析:

注册用户后,在系统的页面上会出现【欢迎:注册用户名】的信息,可以在注册后返回的页面中检查是否出现了这样的内容来判断注册事务是否成功。

通过检查页面可以得到需要判断的代码为:

1.

欢迎:<a class=”dropmenu” id=”viewpro” onmouseover=”showMenu(this.id)”>

所以在检查点函数中需要添加这个内容,为了更好地判断,还需要把注册用户的名字也加进去,最后可以得到下面的代码:

1.     Action()

2.     {

3.             web_url(“注册”,

4.                 “URL=http://192.168.0.200/register.aspx”,

5.                 “TargetFrame=”,

6.                 “Resource=0″,

7.                 “RecContentType=text/html”,

8.                 “Referer=http://192.168.0.200/”,

9.                 “Snapshot=t2.inf”,

10.                “Mode=HTML”,

11.                EXTRARES,

12.                “URL=/templates/default/images/check_error.gif”, ENDITEM,

13.                “URL=/templates/default/images/check_right.gif”, ENDITEM,

14.                “URL=/images/level/3.gif”, ENDITEM,

15.                LAST);

16.

17.            lr_start_transaction(“reg”);

18.

19.            web_reg_find(“Search=Body”,

20.                “SaveCount=regst”,

21.                “Text=欢迎:<a class=”dropmenu” id=”viewpro”

onmouseover= “showMenu(this.id)”>{username}”,

22.                LAST);

23.

24.            web_submit_data(“register.aspx”,

25.                “Action=http://192.168.0.200/register.aspx?createuser=1″,

26.                “Method=POST”,

27.                “TargetFrame=”,

28.                “RecContentType=text/html”,

29.                “Referer=http://192.168.0.200/register.aspx”,

30.                “Snapshot=t11.inf”,

31.                “Mode=HTML”,

32.                ITEMDATA,

33.                “Name=username”, “Value={username}”, ENDITEM,

34.                “Name=password”, “Value=112212″, ENDITEM,

35.                “Name=password2″, “Value=112212″, ENDITEM,

36.                “Name=email”, “Value={username}@cloud.chen”, ENDITEM,

37.                “Name=submit”, “Value=创建用户”, ENDITEM,

38.                “Name=question”, “Value=0″, ENDITEM,

39.                “Name=answer”, “Value=”, ENDITEM,

40.                “Name=realname”, “Value=”, ENDITEM,

41.                “Name=idcard”, “Value=”, ENDITEM,

42.                “Name=mobile”, “Value=”, ENDITEM,

43.                “Name=phone”, “Value=”, ENDITEM,

44.                “Name=gender”, “Value=0″, ENDITEM,

45.                “Name=nickname”, “Value=”, ENDITEM,

46.                “Name=bday_y”, “Value=”, ENDITEM,

47.                “Name=bday_m”, “Value=”, ENDITEM,

48.                “Name=bday_d”, “Value=”, ENDITEM,

49.                “Name=location”, “Value=”, ENDITEM,

50.                “Name=msn”, “Value=”, ENDITEM,

51.                “Name=yahoo”, “Value=”, ENDITEM,

52.                “Name=skype”, “Value=”, ENDITEM,

53.                “Name=icq”, “Value=”, ENDITEM,

54.                “Name=qq”, “Value=”, ENDITEM,

55.                “Name=homepage”, “Value=”, ENDITEM,

56.                “Name=bio”, “Value=”, ENDITEM,

57.                “Name=templateid”, “Value=0″, ENDITEM,

58.                “Name=tpp”, “Value=0″, ENDITEM,

59.                “Name=ppp”, “Value=0″, ENDITEM,

60.                “Name=newpm”, “Value=radiobutton”, ENDITEM,

61.                “Name=pmsound”, “Value=1″, ENDITEM,

62.                “Name=showemail”, “Value=1″, ENDITEM,

63.                “Name=receivesetting”, “Value=2″, ENDITEM,

64.                “Name=receivesetting”, “Value=4″, ENDITEM,

65.                “Name=invisible”, “Value=0″, ENDITEM,

66.                “Name=signature”, “Value=”, ENDITEM,

67.                “Name=sigstatus”, “Value=1″, ENDITEM,

68.                LAST);

69.

70.            if(atoi(lr_eval_string(“{regst}”))>=1)

71.                lr_end_transaction(“reg”, LR_PASS);

72.            else

73.                lr_end_transaction(“reg”,LR_FAIL);

74.            return 0;

75.        }

这里的{username}是一个参数,用来存放注册的用户名,在参数列表中设置了该参数的取值方式和信息。

上一篇:(九)球体


下一篇:C. Count Triangles(前缀和)