LoadRunner脚本日志定位问题案例

引言：在实际工作中，很多使用LoadRunner 的测试人员开发Vuser 脚本时总会遇到这样或那样的问题，影响到性能测试工作的正常进展。而对于性能测试人员而言，Vuser 脚本开发技能是一项基本功，需要在工作中长期修炼才能学有所成。
本文选自《LoadRunner虚拟用户高级开发指南》一书，该书主要为了LoadRunner 使用人员精通脚本开发而创作，目的是分享作者们的经验，使大家在更短的时间内成为LoadRunner 的高手。

本案例来源于一个银行项目的性能调优阶段。
在性能调优过程中发现如下现象：LoadRunner 分析报告中的“缴费”等事务响应时间始终比目标测试模块日志统计到的时间多了200ms 左右。其中，LoadRunner 统计了从发出交易报文到返回执行结果的时间，目标系统则记录了“从收到LoadRunner 报文后进行处理=>发送给其后台模块处理=>其后台模块返回结果=>处理后将执行结果返回给LoadRunner”这一过程的时间。
对于这个问题，依次进行了如下的排查过程。
第一步：首先核实Vuser 脚本，确认脚本本身处理过程是否存在性能消耗。分析的重点主要涉及对报文进行的数据处理、返回结果的分析判断等代码是否有问题。为了分析问题将脚本最终简化成如例4-38 所示，但问题仍然存在。

第二步：分析目标测试模块的日志记录环节，确认没有问题。
第三步：通过监控网络性能，进一步确认了网络没有问题。
上面的几个常见原因依次排除后，基本可以确定这200ms 应该耗费在LoadRunner 与目标测试系统的通信交互过程中，测试团队需要做的是，深入分析时间具体耗费在哪些交互环节上。
分析这类问题，最重要的手段就是深入分析Vuser 脚本的执行日志。打开脚本的“Run-time Settings”对话框，勾选扩展Log 中的“Advanced trace”复选框，以打卡执行过程的详细追踪。注意扩展Log 中的其他选项不要勾选，否则日志输出较多的情况下阅读起来较麻烦，不容易定位问题。
脚本执行完成后，接下来开始分析执行日志来查找问题。为了便于讲解，下面分别列出了发送和接收过程的日志。发送过程日志如下：

可以看到，从15:45:29.148 开始读取buf0，15:45:29.226 完成发送，总共耗时78ms。因此可以判断多消耗的200ms 不可能耗费在发送环节上，从而可以初步断定问题很有可能出在接收报文的环节上。接收过程日志如下：

我们详细分析一下上面的接收过程日志。

15:45:29.288: 准备从socket0 读取542 字节。
15:45:29.319: 准备首次从socket 读取数据，超时设置为10s。
15:45:29.538: 准备读取8192 个字节。
15:45:29.584: 存储读取到的9 个字节。
15:45:29.600: 未接收到指定长度数据，按照超时设置10s 继续等待。
15:45:29.756: 准备读取8192 个字节。
15:45:29.787: 存储读取到的651 个字节。
15:45:29.818: 未接收到指定长度数据，按照超时设置10s 继续等待。
15:45:29.850: 准备读取8192 个字节。
接收完成，接收长度不匹配（期望 542 字节，实际收到 660 字节，相差118 个字节）。
……

在上面的报文接收过程中，可以看到一共进行了3 次接收数据操作：第一次接收了9个字节；第二次接收了651 个字节；第三次接收时Socket 已经关闭因此完成了接收。需要引起注意的是，前两次接收的时候相差时间为15:45:29.787－15:45:29.584=203ms。这203ms是很有可能就是LoadRunner 统计时间与应用程序日志统计结果的偏差。
两次接收时间相差了203ms，这不是正常情况下的网络延迟时间。因此，可以初步怀疑应用程序是分了两次来发送报文：第一次发送了报文头；第二次发送了报文体；之后断开了Socket 连接，所以看到了Vuser 第三次接收报文时没有收到任何内容，并完成接收报文函数的执行。
为了验证上面的假设，先修改一下接收数据过程的超时时间设置，将默认的10s 修改为0.1ms（超时设置应该小于200ms，这样可以只接收到第一次发送的报文头，从而确认每次接收报文过程中形成的接收等待时间是有规律的）。
具体操作为在事务开始前增加语句“lrs_set_recv_timeout2(0,100000);”，修改的脚本如例4-39 所示。

回放脚本，部分执行日志如下：

在上面的日志中可以看到加入超时设置后，可以看到本次共接收了9 字节，基本可以断定应用程序返回报文分两次发送。接下来继续通过实验验证结论：增加一次接收过程来确认是因为应用程序分两次发送报文形成的时间间隔导致浪费了200ms。
修改后的脚本如例4-40 所示。

例4-40 中，第二次接收过程“lrs_receive(“socket0”, “buf2”, LrsLastArg);”语句对应执行日志如下：

在上面的日志中可以看到第二次接收函数执行时能够成功接收到数据，接收完成后Socket 关闭。这时已经可以完全确定应用程序返回交易执行结果过程如下：第一步发送报文头；第二步发送报文体；第三步关闭Socket 连接。通过与开发团队进行反复沟通与确认，证明了测试小组的结论。
在应用程序将两次发送报文合并成一次发送后，LoadRunner 统计结果与应用程序统计结果基本一致。到这一步终于完成了对应用程序底层代码的调优，使大部分交易性能均提高了200ms 以上。

本文选自《LoadRunner虚拟用户高级开发指南》一书。

想及时获得更多精彩文章，可在微信中搜索“博文视点”或者扫描下方二维码并关注。

LoadRunner脚本日志定位问题案例相关推荐

LoadRunner脚本篇
LoadRunner脚本篇 1概述 2脚本录制 3脚本编写 4脚本调试关键词:LoadRunner 性能测试脚本摘要:编写一个准确无误的脚本对性能测试有至关重要的意义.本文介绍 ...
loadrunner 脚本优化-事务时间简介
脚本优化-事务时间简介 by:授客 QQ:1033553122 事务概念事务是指用户在客户端做一种或多种业务所需要的操作集(actions),通过事务开始和结束函数可以标记完成该业务所需要的操作内容 ...
loadrunner脚本练习
loadrunner脚本练习 #include "web_api.h" Action() { char* abort="aborting..."; ...
转：如何在 LoadRunner 脚本中做关联 (Correlation)
如何在 LoadRunner 脚本中做关联 (Correlation) 当录制脚本时,VuGen会拦截client端(浏览器)与server端(网站服务器)之间的对话,并且通通记录下来,产生脚本.在V ...
Loadrunner脚本编程（4）-数据类型操作和字符串操作
http://www.360doc.com/content/10/0806/13/1698198_44078277.shtml 一,数据类型转换没有使用过C编程的LoadRunner脚本编写者会发现 ...
oracle进行日志切换,Oracle存档日志切换案例操作
当前位置:我的异常网» 数据库 » Oracle存档日志切换案例操作 Oracle存档日志切换案例操作 www.myexceptions.net 网友分享于:2014-12-29 浏览:0次 Or ...
性能测试初学_对loadrunner脚本的理解
例子:loadrunner自带的飞机订票系统录制登陆操作脚本对照F1帮助及火狐抓包的理解,整理loadrunner脚本与抓包的关联.此为个人理解,有些未证实,权当记录. Action() { we ...
性能测试：Loadrunner 脚本录制、设置事务、添加检查点、参数化以及添加关联
Loadrunner 脚本录制.设置事务.添加检查点.参数化以及添加关联说明:本文使用loadrunner自带的HP Web Tours Application,录制web脚本没有概念性的解释,直接 ...
Nginx高级优化(2): shell脚本日志切割，连接超时，进程数，网页压缩，防盗链，FPM 参数优化!!
呕心沥血书写,看完后对Nginx了如执掌,不看真的后悔!! shell脚本日志分割设置连接超时 Nginx深入优化更改进程数配置网页压缩配置防盗链 20.0.0.25 主机:开始盗链 20.0 ...
loadrunner脚本编写（转载至虫师博客）
性能测试工程师要懂代码么?答案是必须的.好多测试员认为在loadrunner中编写脚本很难很牛X ,主要是大多测试人员并未做过开发工作,大学的那点程序基础也忘记的差不多了.还有非计算机专业出身的测试员 ...

LoadRunner脚本日志定位问题案例

LoadRunner脚本日志定位问题案例相关推荐

最新文章

热门文章