3.9 事务 - AJava

3.9  事务

3.9.1  响应时间

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

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

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

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

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

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

图3.160  事务响应时间组成

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.161所示。

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

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

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

3.9.2  添加事务

通过事务监控响应时间，需要做的就是在请求的发出前添加一个事务开始的计数器，在请求结束的地方添加一个事务结束的计数器，VuGen会自动计算函数间的时间差。

通过工具栏上的事务按钮即可完成事务的添加操作，在请求之前单击插入事务开始按钮，如图3.162所示。

在弹出对话框中填写事务名称mainpage，如图3.163所示。

图3.162  插入事务开始按钮                 图3.163  设置事务名称

单击OK按钮后，可以得到事务开始的函数：

lr_start_transaction("mainpage");

通过这条语句开始了一个叫做mainpage的事务，然后在请求后添加一个事务结束函数，单击插入事务结束按钮，如图3.164所示。

这里提供了几个选项，选择LR_AUTO 由VuGen自动判断状态，如图3.165所示。

图3.164  插入事务结束按钮         图3.165  设置事务状态判断为LR_AUTO

这样就生成了一个事务结束的函数：

lr_end_transaction("mainpage", LR_AUTO);

这里事务的开始和结束名称需要配对。

事务设置结束，通过这两个函数完成了对事务的设计，运行脚本来看看效果。脚本如下所示：

Action()

{

                       lr_start_transaction("mainpage");

                       web_url("51testing","URL=http://bbs.51testing.com",LAST);

                       lr_end_transaction("mainpage", LR_AUTO);

                       return 0;

}

在日志中可以看到以下信息：

Action.c(3): Notify: Transaction "mainpage" started.

//请求发送返回的相关日志

Action.c(5): Notify: Transaction "mainpage" ended with "Pass" status (Duration: 5.9749).

事务结束的说明中包含了请求所花费的时间为Duration=5.9749秒和事务结束的状态。通过事务可以获得每个操作所消耗的准确时间，例如查询、登录、删除操作。但是对于性能分析来说，这个时间还是太大了，无法有效地帮助我们定位性能瓶颈，LoadRunner能解决这个问题吗？抱歉，LoadRunner只能对自己发出的请求和服务器返回的内容进行网络级别的分析，也就是说LoadRunner能够分析的时间为客户到WWW服务器的时间N1和WWW服务器返回到客户的时间 N6。这些时间主要和网络速度有关，可以用一个LoadRunner的名称来解释，叫做Web Page Breakdown，相关的具体分析可以参考第5.3.5节。

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

事务状态

在默认情况下使用LR_AUTO来作为事务状态，对于一个事务有以下4个状态可以选择。

1．LR_AUTO

LR_AUTO是指事务的状态由系统自动根据默认规则来判断，结果为PASS/FAIL/STOP。

2．LR_PASS

LR_PASS指事务是以PASS状态通过的，说明该事务正确地完成了，并且记录下对应的时间，这个时间就是指做这件事情所需要消耗的响应时间。

3．LR_FAIL

LR_FAIL是指事务以FAIL状态结束，该事务是一个失败的事务，没有完成事务中脚本应该达到的效果，得到的时间不是正确操作的时间，这个时间在后期的统计中将被独立统计。

4．LR_STOP

LR_STOP将事务以STOP状态停止。

事务的PASS和FAIL状态会在场景的对应计数器中记录，包括通过的次数和事务的响应时间，方便后期分析该事务的吞吐量以及响应时间的变化情况。

事务和子事务

在VuGen中可以通过事务来完成一组操作的响应时间监控，如果想监控一个事务中某一步操作的响应时间，就需要使用子事务来完成（当然也可以直接使用事务嵌套）。

Lr_start_sub_transaction("子事务名","父事务名");

Lr_end_sub_transaction("子事务名","子事务状态");

子事务虽然和父事务很像，但是父事务支持的很多函数，在子事务中都无法实现，所以应酌情考虑。

例如：需要做一个登录的事务，想知道打开登录页面和登录操作的时间，就可以使用子事务。

lr_start_transaction("login");

   lr_start_sub_transaction("loginpage","login");

   //打开登录页面

   lr_end_sub_transaction("loginpage",LR_AUTO);

   lr_start_sub_transaction("submitlogin","login");

   //提交登录表单

   lr_end_sub_transaction("submitlogin",LR_AUTO);

lr_end_transaction("login",LR_AUTO);

这样可以得到3个事务的时间，并且清楚地得到打开页面和登录操作以及整个操作的时间。

事务相关的函数

lr_get_transaction_duration("事务名")

//获得对应事务达到该函数运行位置时持续的时间，返回double类型

lr_get_transaction_wasted_time("事务名")

//获得对应事务达到该函数运行位置时的wasted时间，返回double类型

lr_wasted_time(毫秒)

//为一个事务添加wasted时间，无返回

lr_stop_transaction("事务名")

//将一个事务暂停，该函数后的操作都不会被记入事务时间

lr_resume_transaction("事务名")

//将暂停的事务恢复

一般情况下都可以十分简便地获得请求的相应时间，但是对于下载操作来说就并不是那么方便了，这个时候需要利用一个web_get_int_property()函数来解决。例如想获得一个下载操作的响应时间，可以这样写：

Action()

{

int i;

lr_start_transaction("download");

web_url("LoadRunner","URL=http://127.0.0.1/loadrunner.iso",LAST);//下载操作的请求

i=web_get_int_property(HTTP_INFO_DOWNLOAD_SIZE);

if(i>5000)//当下载的文件大小大于5000个字节时认为下载成功，否则失败

lr_end_transaction("download",LR_PASS);

else

lr_end_transaction("download",LR_FAIL);

}

当进行下载操作时，服务器会返回该下载操作的文件大小，所以只需要获得该信息即可，如果还希望对下载时的速度进行测试，那么需要配合关联函数将返回的内容保存到本地才能实现。一般来说对于下载操作的性能测试集中在需要多少时间弹出下载对话框，而后面的内容其实是属于网络带宽的问题了。另一方面现在很少使用IE进行直接下载，而采用迅雷一类的P2P下载工具，所以很少考虑具体下载文件操作对网络和服务器读写操作的影响。

3.9.3  事务时间

一个事务的时间是指持续时间，事务会完全记录下从事务开始到事务结束之间的时间差，那么事务的时间能真实地反映业务操作的时间吗？不能，就好像人用手按秒表来记录短跑时间一样，得出的时间并不是完全准确，存在观察的误差和操作的误差，对于一个事务时间来说，一般由四部分组成，如图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()函数覆盖。

3.9.4  手工事务

前面都是使用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中，那么事务的状态就应该这样判断：

lr_start_transaction("login");

web_reg_find("Search=Body",

                       "SaveCount=loginst",

                       "Text=登录失败",

                       LAST);

//登录请求

If(atoi(lr_eval_string("{loginst}"))>=1))

                       lr_end_transaction("login", LR_FAIL);

else

                       lr_end_transaction("login",LR_PASS);

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

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

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

思考题：

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

业务分析：

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

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

欢迎:

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

Action()

{

                       web_url("注册",

                           "URL=http://192.168.0.200/register.aspx",

                           "TargetFrame=",

                           "Resource=0",

                           "RecContentType=text/html",

                           "Referer=http://192.168.0.200/",

                           "Snapshot=t2.inf",

                           "Mode=HTML",

                           EXTRARES,

                           "URL=/templates/default/images/check_error.gif", ENDITEM,

                           "URL=/templates/default/images/check_right.gif", ENDITEM,

                           "URL=/images/level/3.gif", ENDITEM,

                           LAST);

                       lr_start_transaction("reg");

                       web_reg_find("Search=Body",

                           "SaveCount=regst",

                           "Text=欢迎:{username}",

                           LAST);

                       web_submit_data("register.aspx",

                           "Action=http://192.168.0.200/register.aspx?createuser=1",

                           "Method=POST",

                           "TargetFrame=",

                           "RecContentType=text/html",

                           "Referer=http://192.168.0.200/register.aspx",

                           "Snapshot=t11.inf",

                           "Mode=HTML",

                           ITEMDATA,

                           "Name=username", "Value={username}", ENDITEM,

                           "Name=password", "Value=112212", ENDITEM,

                           "Name=password2", "Value=112212", ENDITEM,

                           "Name=email", "Value={username}@cloud.chen", ENDITEM,

                           "Name=submit", "Value=创建用户", ENDITEM,

                           "Name=question", "Value=0", ENDITEM,

                           "Name=answer", "Value=", ENDITEM,

                           "Name=realname", "Value=", ENDITEM,

                           "Name=idcard", "Value=", ENDITEM,

                           "Name=mobile", "Value=", ENDITEM,

                           "Name=phone", "Value=", ENDITEM,

                           "Name=gender", "Value=0", ENDITEM,

                           "Name=nickname", "Value=", ENDITEM,

                           "Name=bday_y", "Value=", ENDITEM,

                           "Name=bday_m", "Value=", ENDITEM,

                           "Name=bday_d", "Value=", ENDITEM,

                           "Name=location", "Value=", ENDITEM,

                           "Name=msn", "Value=", ENDITEM,

                           "Name=yahoo", "Value=", ENDITEM,

                           "Name=skype", "Value=", ENDITEM,

                           "Name=icq", "Value=", ENDITEM,

                           "Name=qq", "Value=", ENDITEM,

                           "Name=homepage", "Value=", ENDITEM,

                           "Name=bio", "Value=", ENDITEM,

                           "Name=templateid", "Value=0", ENDITEM,

                           "Name=tpp", "Value=0", ENDITEM,

                           "Name=ppp", "Value=0", ENDITEM,

                           "Name=newpm", "Value=radiobutton", ENDITEM,

                           "Name=pmsound", "Value=1", ENDITEM,

                           "Name=showemail", "Value=1", ENDITEM,

                           "Name=receivesetting", "Value=2", ENDITEM,

                           "Name=receivesetting", "Value=4", ENDITEM,

                           "Name=invisible", "Value=0", ENDITEM,

                           "Name=signature", "Value=", ENDITEM,

                           "Name=sigstatus", "Value=1", ENDITEM,

                           LAST);

                       if(atoi(lr_eval_string("{regst}"))>=1)

                           lr_end_transaction("reg", LR_PASS);

                       else

                           lr_end_transaction("reg",LR_FAIL);

                       return 0;

                       }

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