【主编推荐】LoadRunner脚本日志定位问题案例

2016-10-13   出处: 博文视点  作/译者:Broadview

小编说:在实际工作中,很多使用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 以上。



作者简介:

陈绍英,15 年以上IT 系统开发与测试经验。现就职于中国民生银行信息科技部测试管理中心。本人拥有银行、互联网、电子政务等领域IT 系统的测试管理与实施经验,目前主要专注银行系统的性能测试与自动化测试。现负责所在银行IT 系统的性能测试管理、智能一体化测试平台DT的设计、开发与推广等工作,曾经带领团队完成了民生银行新一代系统中100 多个系统的性能测试组织管理与实施工作。本人在软件测试理论与实践方面进行了非常深入的研究和探索,目前已出版原创图书作品三部:《Web 性能测试实战》(2006 年,国内本性能测试理论方面的作品)、《LoadRunner 性能测试实战》(2007 年,国内本讲解LoadRunner的作品)、《LoadRunner 虚拟用户开发指南》(2009 年)三部;翻译作品一部:《软件测试与持续质量改进》第二、三版(2008 年、2011 年);在《金融科技治理与研究》、《程序员》等杂志上发表过《银行IT 系统功能&性能一体化测试理论及应用》、《性能测试》、《治疗软件亚健康》、《性能测试兵法》、《架构设计阶段的性能测试》、《中小型IT 企业产品测试案例解析》等多篇文章。本人在性能测试方面的研究,丰富了国内IT 领域性能测试相关的理论体系,从理论与实践推动了性能测试在国内的发展。已经出版的图书、视频等作品,把一批人带入了性能测试领域,并指导了很多项目经理、测试工程师非常系统地的规划、设计、实施性能测试工作。《Web 性能测试实战》一书中提出的“全面性能测试模型”,成为很多测试团队组织与开展性能测试工作的指导原则。

                                                    



声明:本文为本站编辑转载,文章版权归原作者所有。文章内容为作者个人观点,本站只提供转载参考(依行业惯例严格标明出处和作译者),目的在于传递更多专业信息,普惠测试相关从业者,开源分享,推动行业交流和进步。 如涉及作品内容、版权和其它问题,请原作者及时与本站联系(QQ:1017718740),我们将第一时间进行处理。本站拥有对此声明的最终解释权!欢迎大家通过新浪微博(@测试窝)或微信公众号(测试窝)关注我们,与我们的编辑和其他窝友交流。
411° /4111 人阅读/0 条评论 发表评论

登录 后发表评论
最新文章