LoadRunner脚本日志定位问题案例

本文涉及的产品
日志服务 SLS,月写入数据量 50GB 1个月
简介: 在实际工作中,很多使用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虚拟用户高级开发指南》一书。
图片描述

相关实践学习
【涂鸦即艺术】基于云应用开发平台CAP部署AI实时生图绘板
【涂鸦即艺术】基于云应用开发平台CAP部署AI实时生图绘板
相关文章
|
2月前
|
JSON 缓存 测试技术
程序出错瞎找?教你写“会说话”的错误日志,秒定位原因
错误日志是排查问题的“导航地图”。本文详解错误三大来源:参数非法、交互故障、逻辑疏漏,并分享写好日志的6大原则——完整、具体、直接、集成经验、格式统一、突出关键字,助你快速定位问题,提升系统可维护性。
271 0
|
Java Shell
「sh脚步模版自取」测试线排查的三个脚本:启动、停止、重启、日志保存
「sh脚步模版自取」测试线排查的三个脚本:启动、停止、重启、日志保存
195 1
|
8月前
|
数据库连接 测试技术 Windows
【YashanDB知识库】windows配置ODBC跟踪日志, 使用日志定位问题
【YashanDB知识库】windows配置ODBC跟踪日志, 使用日志定位问题
|
12月前
|
测试技术 开发工具 git
写了BUG还想跑——闲鱼异常日志问题自动追踪-定位-分发机制
为了高效地发现、定位和解决预发问题,闲鱼团队研发了一套异常日志问题自动追踪-定位-分发机制。这套机制通过自动化手段,实现了异常日志的定时扫描、精准定位和自动分发,显著降低了开发和测试的成本,提高了问题解决的效率。
529 15
写了BUG还想跑——闲鱼异常日志问题自动追踪-定位-分发机制
|
12月前
|
监控 数据挖掘 数据安全/隐私保护
Python脚本:自动化下载视频的日志记录
Python脚本:自动化下载视频的日志记录
|
Prometheus Cloud Native Go
Golang语言之Prometheus的日志模块使用案例
这篇文章是关于如何在Golang语言项目中使用Prometheus的日志模块的案例,包括源代码编写、编译和测试步骤。
261 4
Golang语言之Prometheus的日志模块使用案例
|
存储 数据可视化 安全
一个简单案例,带你看懂GC日志!
一个简单案例,带你看懂GC日志!
111 0
一个简单案例,带你看懂GC日志!
|
缓存 监控 算法
分析慢日志文件来优化 PHP 脚本的性能
分析慢日志文件来优化 PHP 脚本的性能
|
Java Shell Linux
【Linux入门技巧】新员工必看:用Shell脚本轻松解析应用服务日志
关于如何使用Shell脚本来解析Linux系统中的应用服务日志,提供了脚本实现的详细步骤和技巧,以及一些Shell编程的技能扩展。
302 0
【Linux入门技巧】新员工必看:用Shell脚本轻松解析应用服务日志
|
运维 监控 Ubuntu
一键启动日志魔法:揭秘ELK自动安装脚本的神秘面纱!
【8月更文挑战第9天】在数据驱动时代,高效处理日志至关重要。ELK Stack(Elasticsearch、Logstash、Kibana)是强大的日志分析工具,但其复杂的安装配置常让初学者望而却步。本文介绍如何编写ELK自动安装脚本,简化部署流程。脚本适用于Ubuntu系统,自动完成ELK下载、安装及基本配置,包括依赖项安装、服务启动及自启设置,极大降低了使用门槛,助力运维人员和开发者轻松构建日志分析平台。
406 6

热门文章

最新文章