Bug 63411 - JMeter Summariser: Flushed statistics according to interval even if no sample occured
Summary: JMeter Summariser: Flushed statistics according to interval even if no sample...
Status: NEW
Alias: None
Product: JMeter
Classification: Unclassified
Component: Main (show other bugs)
Version: 2.10
Hardware: All All
: P2 enhancement (vote)
Target Milestone: JMETER_5.2
Assignee: JMeter issues mailing list
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-05-08 10:00 UTC by Liu XP
Modified: 2019-05-24 14:46 UTC (History)
1 user (show)



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Liu XP 2019-05-08 10:00:14 UTC
I have set summariser.interval=10 in jmeter.properties file. But it couldn't be flushed logs every time.

The following is part of detail logs. Please take a look at 2019/04/03 22:49:44 and 2019/04/03 22:52:35 timestamp.


...
2019/04/03 22:49:01 INFO  - jmeter.reporters.Summariser: summary +  24582 in 00:00:10 = 2395.7/s Avg:    17 Min:     0 Max:   705 Err:     1 (0.0041%) Active: 64 Started: 45 Finished: 0
2019/04/03 22:49:01 INFO  - jmeter.reporters.Summariser: summary = 13118986 in 00:59:39 = 3665.8/s Avg:     9 Min:     0 Max: 694682 Err: 10091 (0.0769%)
2019/04/03 22:49:11 INFO  - jmeter.reporters.Summariser: summary +  23996 in 00:00:10 = 2449.8/s Avg:    17 Min:     0 Max:   747 Err:     0 (0.0000%) Active: 64 Started: 45 Finished: 0
2019/04/03 22:49:11 INFO  - jmeter.reporters.Summariser: summary = 13142982 in 00:59:49 = 3662.5/s Avg:     9 Min:     0 Max: 694682 Err: 10091 (0.0768%)
2019/04/03 22:49:21 INFO  - jmeter.reporters.Summariser: summary +  23835 in 00:00:10 = 2395.7/s Avg:    18 Min:     0 Max:   780 Err:     2 (0.0084%) Active: 64 Started: 45 Finished: 0
2019/04/03 22:49:21 INFO  - jmeter.reporters.Summariser: summary = 13166817 in 00:59:59 = 3659.0/s Avg:     9 Min:     0 Max: 694682 Err: 10093 (0.0767%)
2019/04/03 22:49:22 INFO  - jmeter.JMeter: Finished remote host: 10.100.17.231 (1554302962982) 
2019/04/03 22:49:23 INFO  - jmeter.JMeter: Finished remote host: 10.100.17.232 (1554302963128) 
2019/04/03 22:49:23 INFO  - jmeter.JMeter: Finished remote host: 10.100.17.234 (1554302963373) 
2019/04/03 22:49:23 INFO  - jmeter.JMeter: Finished remote host: 10.100.17.227 (1554302963662) 
2019/04/03 22:49:23 INFO  - jmeter.JMeter: Finished remote host: 10.100.17.228 (1554302963824) 
2019/04/03 22:49:23 INFO  - jmeter.JMeter: Finished remote host: 10.100.17.229 (1554302963846) 
2019/04/03 22:49:44 INFO  - jmeter.reporters.Summariser: summary +   5936 in 00:00:24 =  248.9/s Avg:    19 Min:     0 Max:   710 Err:     0 (0.0000%) Active: 2 Started: 45 Finished: 62
2019/04/03 22:49:44 INFO  - jmeter.reporters.Summariser: summary = 13172753 in 01:00:22 = 3636.5/s Avg:     9 Min:     0 Max: 694682 Err: 10093 (0.0766%)
2019/04/03 22:49:44 INFO  - jmeter.JMeter: Finished remote host: 10.100.17.233 (1554302984986) 
2019/04/03 22:52:35 INFO  - jmeter.reporters.Summariser: summary +    297 in 00:02:50 =    1.7/s Avg:   891 Min:     0 Max: 258593 Err:     0 (0.0000%) Active: 1 Started: 45 Finished: 63
2019/04/03 22:52:35 INFO  - jmeter.reporters.Summariser: summary = 13173050 in 01:03:13 = 3473.4/s Avg:     9 Min:     0 Max: 694682 Err: 10093 (0.0766%) 2019-04-03 22:52:35 
2019/04/03 22:52:35 INFO  - jmeter.reporters.Summariser: summary +    253 in 00:00:00 = 2480.4/s Avg:  1045 Min:     0 Max: 258795 Err:     0 (0.0000%) Active: 0 Started: 45 Finished: 64
2019/04/03 22:52:35 INFO  - jmeter.reporters.Summariser: summary = 13173303 in 01:03:13 = 3473.4/s Avg:     9 Min:     0 Max: 694682 Err: 10093 (0.0766%)
2019/04/03 22:52:35 INFO  - jmeter.JMeter: Finished remote host: 10.100.17.230 (1554303155273) 
2019/04/03 22:52:40 INFO  - jmeter.JMeter: Interrupting RMI Reaper 


I found when there was no sampler occurred, the entry point of interval in src/core/org/apache/jmeter/reporters/Summariser.java line 174 would not be executed.
Comment 1 Philippe Mouawad 2019-05-13 12:04:23 UTC
Hello,
Thanks for report.
Yes you are right, in fact the 10s is in reality "10 s if there were SampleResults" received in interval.

If you have a better proposal, feel free to contribute a PR or some description of what you would prefer.

Thanks
Regards
Comment 2 Liu XP 2019-05-15 06:51:01 UTC
Can we add a message line with empty result data as below?

2019/04/03 22:49:54 INFO  - jmeter.reporters.Summariser: summary +   0 in 00:00:34 =  0/s Avg:    0 Min:     0 Max:   0 Err:     0 (0.0000%) Active: 2 Started: 45 Finished: 62
2019/04/03 22:49:54 INFO  - jmeter.reporters.Summariser: summary = 13172753 in 01:00:34 = 3536.5/s Avg:     9 Min:     0 Max: 694682 Err: 10093 (0.0766%)
Comment 3 Philippe Mouawad 2019-05-15 07:09:34 UTC
The flushing would need to be changed, since currently it only occurs on sampleOccurred(SampleEvent e), so no sample == no flushing.

We would need to decouple results collection in sampleOccurred(SampleEvent e) from flushing which should then be controlled by a timer.

Would you be willing to propose a PR ?

Thanks
Comment 4 Liu XP 2019-05-24 14:13:42 UTC
Hi Philippe,

Where can I propose a PR?
Comment 5 Philippe Mouawad 2019-05-24 14:46:13 UTC
(In reply to Liu XP from comment #4)
> Hi Philippe,
> 
> Where can I propose a PR?

Hello Liu (I hope I don't make a mistake on your first name),

You can propose a PR here:
- https://github.com/apache/jmeter

Read this for all details:

- https://github.com/apache/jmeter/blob/trunk/CONTRIBUTING.md

Thanks for your proposals.

Regards