Bug 63856

Summary: Bugged informations in CSV for "Connect Times" with subresults=false
Product: JMeter - Now in Github Reporter: pierre.astruc
Component: MainAssignee: JMeter issues mailing list <issues>
Status: RESOLVED FIXED    
Severity: normal CC: p.mouawad
Priority: P2 Keywords: PatchAvailable
Version: 5.1.1   
Target Milestone: JMETER_5.3.0   
Hardware: All   
OS: All   
Attachments: Graph_problem_in_CSV_mode.pdf
lib.7z
Z_Result.jmx
Z_SimpleTest.jmx
Graph_problem_in_CSV_mode_5.1.1
Z_VerySimpleTest
Just2Get.jmx
Calculate connectTime for parent sampler

Description pierre.astruc 2019-10-16 21:15:28 UTC
Created attachment 36839 [details]
Graph_problem_in_CSV_mode.pdf

Hello all,
I got a problem with the export of CSV results, somes values are false when compared with the GUI version !

Step to reproduce:
- Download latest nightly https://ci.apache.org/projects/jmeter/nightlies/
- Unzip archive
- Edit jmeter.properties and change this setting:

jmeter.save.saveservice.subresults=false

- Run the attached Z_SimpleTest.jmx in command line mode. (this test have 2 "Transaction Controller" + "Generate parent sample")

jmeter -n -t Z_SimpleTest.jmx -l Z_Result.csv

- Unzip lib.7z into lib folder (jp@gc plugins-graphs)
- Open jmeter GUI and open Z_Result.jmx
- Open "1 - Active Threads" listener and clic "Enter" in filename "Z_Result.csv" : Graph is OK
- Open "2 - Transactions" listener and clic "Enter" in filename "Z_Result.csv" : Graph is OK
- Open "3 - Response Codes" listener and clic "Enter" in filename "Z_Result.csv" : ** Broken ! response code of all subresults are not correctly counted **
- Open "4 - Bytes Throughput" listener and clic "Enter" in filename "Z_Result.csv" : Graph is OK
- Open "5 - Connect Times" listener and clic "Enter" in filename "Z_Result.csv" : ** Empty ! the connect times are only recorded for subresults and not propagated to "transaction controller" parent **
- Open "6 - Response Times" listener and clic "Enter" in filename "Z_Result.csv" : Graph is OK
- Open "2 - Transactions" listener and clic "Enter" in filename "Z_Result.csv" : Table is OK

If you want to see the correct result in GUI mode, simply merge the Z_Result.jmx into Z_SimpleTest.jmx and run the test, you will see that the values of "3 - Response Codes" and "5 - Connect Times" are correct :)

Last attached Graph_problem_in_CSV_mode.pdf file compare the graphs in CSV vs GUI mode, this will quickly show you the 2 problems of CSV result output.

Thanks for reading!
Pierre
Comment 1 pierre.astruc 2019-10-16 21:16:33 UTC
Created attachment 36840 [details]
lib.7z
Comment 2 pierre.astruc 2019-10-16 21:16:51 UTC
Created attachment 36841 [details]
Z_Result.jmx
Comment 3 pierre.astruc 2019-10-16 21:17:06 UTC
Created attachment 36842 [details]
Z_SimpleTest.jmx
Comment 4 Philippe Mouawad 2019-10-16 21:30:20 UTC
(In reply to pierre.astruc from comment #3)
> Created attachment 36842 [details]
> Z_SimpleTest.jmx

Hello Pierre,
Is this specific to 5.2 or also in 5.1.1 ?

Thanks
Comment 5 pierre.astruc 2019-10-17 08:06:33 UTC
Hello Philippe,

This is one excellent question !
So I performed the exact same test with apache-jmeter-5.1.1 (r1855137)
http://miroir.univ-lorraine.fr/apache/jmeter/binaries/apache-jmeter-5.1.1.zip

And the result are the same, 2 problems with CSV, all graph OK with GUI (see attachement).
So the problem was already present.

Pierre
Comment 6 pierre.astruc 2019-10-17 08:06:52 UTC
Created attachment 36844 [details]
Graph_problem_in_CSV_mode_5.1.1
Comment 7 Philippe Mouawad 2019-10-17 19:12:40 UTC
(In reply to pierre.astruc from comment #6)
> Created attachment 36844 [details]
> Graph_problem_in_CSV_mode_5.1.1

Thanks for feedback.
What was the last version that worked the way you describe it ?

Thanks
Comment 8 pierre.astruc 2019-10-17 21:13:38 UTC
Hello Philippe,

I don't know, maybe this problem is present since beginning :)
So I build a VerySimpleTest (attached) and use the following command with some different build to check.

jmeter -n -t Z_VerySimpleTest.jmx -l Z_Result.csv

I download the build from https://archive.apache.org/dist/jmeter/binaries/?C=M;O=A
And edit jmeter.properties to made only one change : "jmeter.save.saveservice.subresults=false"
Results:

jakarta-jmeter-2.5.1 	: All graphs ok except "1- Active Threads" + "3 - Response Codes" + "5 - Connect Times"
apache-jmeter-2.13	: CSV broken ?
apache-jmeter-3.0	: All graphs ok except "3 - Response Codes" + "5 - Connect Times"
apache-jmeter-3.3	: All graphs ok except "3 - Response Codes" + "5 - Connect Times"
apache-jmeter-4.0	: All graphs ok except "3 - Response Codes" + "5 - Connect Times"
apache-jmeter-5.0	: All graphs ok except "3 - Response Codes" + "5 - Connect Times"

So this problem is present since beginning.
I think graph 3 and 5 are not working correcly in CSV with "jmeter.save.saveservice.subresults=false" and "Generate parent sample" in test plan.
Comment 9 pierre.astruc 2019-10-17 21:14:29 UTC
Created attachment 36847 [details]
Z_VerySimpleTest
Comment 10 pierre.astruc 2019-10-22 15:43:57 UTC
Hello all,

I made more test, and without the "Generate parent sample" option, I can see that the "Connect Times" are corrects for all "HTTP Request" inside the Transaction Controller, but not summed on the corresponding Transaction Controller.

The fix should be easy, we should do like we do for the "Response Time": sum the "Connect Times" of all "HTTP Request" of one "Transaction Controller", and keep this value for the transaction controller instead of 0.

Pierre
Comment 11 pierre.astruc 2019-11-08 21:46:58 UTC
Created attachment 36874 [details]
Just2Get.jmx

Hello guys,

I made a new test plan to reproduce the problem, please find Just2Get.jmx attached :)
I confirmed the problem is still present in Jmeter "5.2-SNAPSHOT a8d030b" (08/11/2019).

In this Just2Get.jmx plan, you will only find 2 x "HTTP Request", 1 x "Transaction Controller", and 1 x "View Results Tree".
The "View Results Tree" Listener is configured to write results to "results.csv" file with default options.

---------
Step 1: Play the test (it will only perform one run with one thread).
The result will be correct: Connect time of the Transaction Controller (197ms) will be the sum of G01 (197ms) + G02 (0ms)
---------
" 
timeStamp,elapsed,label,responseCode,responseMessage,threadName,dataType,success,failureMessage,bytes,sentBytes,grpThreads,allThreads,URL,Latency,IdleTime,Connect
1573248942696,243,G01 /,200,OK,Thread Group 1-1,text,true,,4352,366,1,1,https://jmeter.apache.org/,242,0,197
1573248942940,92,G02 /images/logo.svg,200,OK,Thread Group 1-1,text,true,,35595,381,1,1,https://jmeter.apache.org/images/logo.svg,89,0,0
1573248942688,335,Transaction Controller,200,"Number of samples in transaction : 2, number of failing samples : 0",Thread Group 1-1,,true,,39947,747,1,1,null,331,10,197
"


---------
Step 2: Check the "Generate parent sample" on the transaction controller and replay the test.
The result will be incorrect: Connect time of the Transaction Controller (0ms) will not be the sum of G01 (168ms) + G02 (0ms)
---------
"
timeStamp,elapsed,label,responseCode,responseMessage,threadName,dataType,success,failureMessage,bytes,sentBytes,grpThreads,allThreads,URL,Latency,IdleTime,Connect
1573249185428,306,Transaction Controller,200,"Number of samples in transaction : 2, number of failing samples : 0",Thread Group 1-1,,true,,39947,747,1,1,null,0,3,0
1573249185430,214,G01 /,200,OK,Thread Group 1-1,text,true,,4352,366,1,1,https://jmeter.apache.org/,214,0,168
1573249185645,92,G02 /images/logo.svg,200,OK,Thread Group 1-1,text,true,,35595,381,1,1,https://jmeter.apache.org/images/logo.svg,90,0,0
"


Thanks for any time you can find to investigate :)
Cheers,

Pierre
Comment 12 Felix Schumacher 2020-02-24 13:41:05 UTC
Created attachment 37037 [details]
Calculate connectTime for parent sampler

Hi Pierre,
you might want to try the attached patch, which adds connectTime to the results of the parent sampler.

I hope others will have a look at the patch, too. I don't use transaction controllers much and don't know, what expectations others have on their results.

Another thing that came to my mind, is that the connect time for http samplers are probably not correct, when a redirection is involved. The reported connect time seems to be the connect time of the first redirect, only.
Comment 13 pierre.astruc 2020-02-26 16:44:36 UTC
Hello Felix,

Thanks for the quick patch :)
I just tested it over jmeter-5.2.1 source and it's working as expected !
For me you can include it in the master code for future.

Pierre

example of CSV without "generate parent sampler" (OK)
-------
1582734889746,551,Transaction Controller,200,"Number of samples in transaction : 2, number of failing samples : 0",Thread Group 1-1,,true,,40011,747,1,1,null,0,1003,277
1582734890248,368,G01 /,200,OK,Thread Group 1-1,text,true,,4384,366,1,1,https://jmeter.apache.org/,368,0,277
1582734891117,183,G02 /images/logo.svg,200,OK,Thread Group 1-1,text,true,,35627,381,1,1,https://jmeter.apache.org/images/logo.svg,180,0,0
1582734891301,537,Transaction Controller,200,"Number of samples in transaction : 2, number of failing samples : 0",Thread Group 1-1,,true,,40011,747,1,1,null,0,1000,268
1582734891801,357,G01 /,200,OK,Thread Group 1-1,text,true,,4384,366,1,1,https://jmeter.apache.org/,357,0,268
1582734892658,180,G02 /images/logo.svg,200,OK,Thread Group 1-1,text,true,,35627,381,1,1,https://jmeter.apache.org/images/logo.svg,176,0,0


example of CSV with "generate parent sample" (OK)
-------
1582734889746,551,Transaction Controller,200,"Number of samples in transaction : 2, number of failing samples : 0",Thread Group 1-1,,true,,40011,747,1,1,null,0,1003,277
1582734891301,537,Transaction Controller,200,"Number of samples in transaction : 2, number of failing samples : 0",Thread Group 1-1,,true,,40011,747,1,1,null,0,1000,268
Comment 14 Philippe Mouawad 2020-02-26 18:08:00 UTC
Reopening as patch is not merged
Comment 15 Felix Schumacher 2020-02-26 20:42:22 UTC
Patch is committed. @Pierre, it would be nice, if you would test the next nightly again.

commit 06a7522d6c5de0d099bb5e8641a763b28041187d
Author: Felix Schumacher <felix.schumacher@internetallee.de>
AuthorDate: Mon Feb 24 14:36:53 2020 +0100

    Calculate connectTime for parent sampler in transaction controller
    
    Bugzulla Id: 63856
---
 .../src/main/java/org/apache/jmeter/control/TransactionSampler.java   | 4 ++++
 xdocs/changes.xml                                                     | 2 ++
 2 files changed, 6 insertions(+)
Comment 16 pierre.astruc 2020-03-02 11:28:28 UTC
Hello Felix, Hello Philippe,

I just tested the nightly of 02/03 (704adb9), and it's working as expected :)
Connect time of transaction controller is the correct sum of all connect time of inside queries, like other columns.
Thanks for fixing this !

Cheers,
Comment 17 The ASF infrastructure team 2022-09-24 20:38:18 UTC
This issue has been migrated to GitHub: https://github.com/apache/jmeter/issues/5184