lr Controller中事务响应时间与日志中的不一致。

manchao 发表于 2013-9-4 11:33:51

上图是运行场景后的事务响应时间，最大才0.126秒，但是查看运行日志是，却有88多秒的。日志如下：
Virtual User Script started at : 2013-09-04 11:10:53
Starting action vuser_init.
Web Services replay version 11.0.0 for Windows 7; Toolkit: "NotDefined"; build 9409
Run-Time Settings file: "C:\Users\suchenhui\AppData\Local\Temp\lr5tmpdirLz7.322\lrcfg1jC.323\cfgGxT.326"
Vuser directory: "I:\lr\lr_script\mssql_connect"
Vuser output directory: "I:\lr\lr_script\mssql_connect"
LOCAL start date/time:2013-09-04 11:10:53
vuser_init.c(3): Warning: The string 'SQL Server' with parameter delimiters is not a parameter.
vuser_init.c(3): DB Connection "Connect" started ... Wait ....
vuser_init.c(9): 连接数据库成功
Ending action vuser_init.
Running Vuser...
Starting iteration 1.
Starting action Action.
Action.c(8): Rendezvous 查询库存
Action.c(9): Notify: Transaction "SQL_Select" started.
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '1'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="C216"
Action.c(13): Notify: Next row for parameter code = 2 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '2'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="B395"
Action.c(13): Notify: Next row for parameter code = 3 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '3'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="CP88"
Action.c(13): Notify: Next row for parameter code = 4 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '4'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="BZ29"
Action.c(13): Notify: Next row for parameter code = 5 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '5'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="C510"
Action.c(13): Notify: Next row for parameter code = 6 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '6'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="BW39"
Action.c(13): Notify: Next row for parameter code = 7 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '7'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="HC42"
Action.c(13): Notify: Next row for parameter code = 8 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '8'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="BM89"
Action.c(13): Notify: Next row for parameter code = 9 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '9'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="BS61"
Action.c(13): Notify: Next row for parameter code = 10 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '10'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="HF42"
Action.c(13): Notify: Next row for parameter code = 11 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '11'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="HC63"
Action.c(13): Notify: Next row for parameter code = 12 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '12'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="C603"
Action.c(13): Notify: Next row for parameter code = 13 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '13'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="CA57"
Action.c(13): Notify: Next row for parameter code = 14 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '14'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="I557"
Action.c(13): Notify: Next row for parameter code = 15 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '15'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="BS29"
Action.c(13): Notify: Next row for parameter code = 16 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '16'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="C349"
Action.c(13): Notify: Next row for parameter code = 17 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '17'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="C795"
Action.c(13): Notify: Next row for parameter code = 18 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '18'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="CR12"
Action.c(13): Notify: Next row for parameter code = 19 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '19'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="HI50"
Action.c(13): Notify: Next row for parameter code = 20 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '20'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="HD09"
Action.c(13): Notify: Next row for parameter code = 21 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '21'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="CN70"
Action.c(13): Notify: Next row for parameter code = 22 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '22'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="BJ89"
Action.c(13): Notify: Next row for parameter code = 23 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '23'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="C401"
Action.c(13): Notify: Next row for parameter code = 24 .
Action.c(13): Notify: Getting new value for parameter 'code': table = 'code.dat' column = '0' row = '24'.
Action.c(13): Notify: Parameter Substitution: parameter "code" ="C210"
Action.c(13): SQL Statementexecution "PerformQuery" started
Action.c(13): ================================================
Action.c(21): The query returned 105 rows.
Action.c(24): Notify: Transaction "SQL_Select" ended with "Pass" status (Duration: 88.7412 Wasted Time: 88.7389).
Ending action Action.
Ending iteration 1.
Ending Vuser...
Starting action vuser_end.
vuser_end.c(3): DB disconnect "Disconnect" started
vuser_end.c(3): ================================================
vuser_end.c(6): 断开连接成功
Ending action vuser_end.
Vuser Terminated.

补充：在界面上运行与日志中的时间是差不多的。
为什么在Controller的事务响应时间却那么少呢

hlhelei 发表于 2013-9-4 11:58:51

看清楚Duration: 88.7412 Wasted Time: 88.7389
二者之差才是事务响应时间
Wasted Time 是代码消耗时间

manchao 发表于 2013-9-4 12:20:40

看清楚Duration: 88.7412 Wasted Time: 88.7389
二者之差才是事务响应时间
Wasted Time 是代码消耗时间
hlhelei 发表于 2013-9-4 11:58 http://bbs.51testing.com/images/common/back.gif

谢谢指点。请问，在Controller或者Analysis中，我能获得到这个Wasted Time吗？

manchao 发表于 2013-9-4 12:20:45

hlhelei 发表于 2013-9-4 13:02:48

Analysis中看不到 Wasted Time 这些值的,

页: [1]

51Testing软件测试论坛 's Archiver

lr Controller中事务响应时间与日志中的不一致。