Bug 60453

Summary: The Min and Max value in no GUI summary log are not correct when using remote statistical test mode.
Product: JMeter Reporter: Liu XP <liu_xp2003>
Component: MainAssignee: JMeter issues mailing list <issues>
Status: RESOLVED DUPLICATE    
Severity: normal CC: liu_xp2003, p.mouawad
Priority: P2    
Version: 3.1   
Target Milestone: ---   
Hardware: All   
OS: All   
Bug Depends on:    
Bug Blocks: 43484    
Attachments: src/core/org/apache/jmeter/samplers/SampleResult.java
src/core/org/apache/jmeter/samplers/StatisticalSampleResult.java
src/core/org/apache/jmeter/reporters/SummariserRunningSample.java
Fixed patch based on JMeter head commit on github site.

Description Liu XP 2016-12-08 03:39:07 UTC
In JMeter org.apache.jmeter.reports.SummariserRunningSample
the max and min using res.getTime() to get one sampler elapsedTime.
But in statistical running mode, SampleResut.elapsedTime recorded multiple sampler's  elapsed time.

Thus, in summary log, the min response time is bigger than Avg response time and Max time is also not correct.

Current Result in summering log:
Starting remote engines
Starting the test @ Thu Dec 08 11:20:17 CST 2016 (1481167217382)
Remote engines have been started
Waiting for possible Shutdown/StopTestNow/Heapdump message on port 4445
summary + 374320 in 00:00:11 = 34417.1/s Avg:     6 Min:    47 Max:  2270 Err:
   0 (0.0000%) Active: 400 Started: 300 Finished: 0
summary + 1715500 in 00:00:30 = 57185.2/s Avg:     6 Min:   635 Max:  3679 Err:
    0 (0.0000%) Active: 400 Started: 300 Finished: 0
summary = 2089820 in 00:00:41 = 51124.6/s Avg:     6 Min:    47 Max:  3679 Err:
    0 (0.0000%)
summary + 1723400 in 00:00:30 = 57446.7/s Avg:     6 Min:   637 Max:  3692 Err:
    0 (0.0000%) Active: 400 Started: 300 Finished: 0
summary = 3813220 in 00:01:11 = 53799.8/s Avg:     6 Min:    47 Max:  3692 Err:
    0 (0.0000%)
summary + 1725100 in 00:00:30 = 57507.2/s Avg:     6 Min:   629 Max:  3677 Err:
    0 (0.0000%) Active: 400 Started: 300 Finished: 0
summary = 5538320 in 00:01:41 = 54901.7/s Avg:     6 Min:    47 Max:  3692 Err:
    0 (0.0000%)
...


I fixed in org.apache.jmeter.reports.SummariserRunningSample
Line123:         long aTimeInMillis = res.getTime();
changed to
long aTimeInMillis = res.getEndTime() - res.getStartTime() - res.getIdleTime();
Comment 1 Liu XP 2016-12-08 06:06:16 UTC
Oops!
My change couldn't fix this issue.
Comment 2 Liu XP 2016-12-11 00:38:07 UTC
Created attachment 34514 [details]
src/core/org/apache/jmeter/samplers/SampleResult.java
Comment 3 Liu XP 2016-12-11 00:45:09 UTC
Created attachment 34515 [details]
src/core/org/apache/jmeter/samplers/StatisticalSampleResult.java
Comment 4 Liu XP 2016-12-11 00:46:00 UTC
Created attachment 34516 [details]
src/core/org/apache/jmeter/reporters/SummariserRunningSample.java
Comment 5 Liu XP 2016-12-11 00:47:11 UTC
To fixed this issue, I updated code in three files. Attached snapshot.
Maybe, it is not best solution and increased a little CPU usage, but it could get correct result as following.


Starting remote engines
Starting the test @ Sun Dec 11 00:55:42 CST 2016 (1481388942822)
summary +      1 in 00:00:00 =   38.5/s Avg:     2 Min:     2 Max:     2 Err:     0 (0.0000%) Active: 2 Started: 1 Finished: 0
Remote engines have been started
Waiting for possible Shutdown/StopTestNow/Heapdump message on port 4445
summary + 881519 in 00:00:06 = 148403.9/s Avg:     2 Min:     0 Max:    27 Err:     0 (0.0000%) Active: 700 Started: 634 Finished: 0
summary = 881520 in 00:00:06 = 146189.1/s Avg:     2 Min:     0 Max:    27 Err:     0 (0.0000%)
summary + 2667000 in 00:00:10 = 266726.7/s Avg:     2 Min:     0 Max:  3002 Err:     0 (0.0000%) Active: 700 Started: 634 Finished: 0
summary = 3548520 in 00:00:16 = 221381.2/s Avg:     2 Min:     0 Max:  3002 Err:     0 (0.0000%)
summary + 2674500 in 00:00:10 = 267423.3/s Avg:     2 Min:     0 Max:   211 Err:     0 (0.0000%) Active: 700 Started: 634 Finished: 0
summary = 6223020 in 00:00:26 = 239061.9/s Avg:     2 Min:     0 Max:  3002 Err:     0 (0.0000%)
summary + 2651500 in 00:00:10 = 265176.5/s Avg:     2 Min:     0 Max:  3002 Err:     0 (0.0000%) Active: 700 Started: 634 Finished: 0
summary = 8874520 in 00:00:36 = 246309.2/s Avg:     2 Min:     0 Max:  3002 Err:     0 (0.0000%)
summary + 2636000 in 00:00:10 = 263573.6/s Avg:     2 Min:     0 Max:   207 Err:     0 (0.0000%) Active: 700 Started: 634 Finished: 0
summary = 11510520 in 00:00:46 = 250060.2/s Avg:     2 Min:     0 Max:  3002 Err:     0 (0.0000%)
...
Comment 6 Philippe Mouawad 2016-12-13 20:48:20 UTC
Hello,
Thanks for the analysis and patch , but could you provide a Text based patch instead of screenshots of code ?
Thank you
Comment 7 Liu XP 2016-12-24 15:41:23 UTC
Created attachment 34553 [details]
Fixed patch based on JMeter head commit on github site.

Uploaded patch.
Comment 8 Liu XP 2016-12-24 15:42:16 UTC
Uploaded patch and changed bug status.
Comment 9 Philippe Mouawad 2016-12-30 21:24:17 UTC
Thanks for patch, unfortunately I don't think it can be integrated this way:
- minTime and maxTime should not be in SampleResult if only used for StatisticalSampleResult
- In SummariserRunningSample, getSampleCount() can be higher than 1 (see PublisherSampler and SubscriberSampler) without being related to StatisticalSampleResult, in this case the change in SummariserRunningSample would not be correct

I'll be happy to integrate a fixed version of the patch.
I've linked this bug to Bug 43484 as I think it is related and the issue there might also interest you.

Regards
Comment 10 Philippe Mouawad 2016-12-30 21:25:44 UTC
Marking as duplicate of Bug 43484.
Any patch should be submitted in the 43484 one.

*** This bug has been marked as a duplicate of bug 43484 ***