Bug 63711

Summary: Number of requests are growing without any reason in nightly build
Product: JMeter Reporter: pierre.astruc
Component: MainAssignee: JMeter issues mailing list <issues>
Severity: regression CC: p.mouawad
Priority: P2 Keywords: FixedInTrunk
Version: Nightly (Please specify date)   
Target Milestone: JMETER_5.2   
Hardware: All   
OS: All   
Attachments: SimpleTest.jmx
5.1.1_vs_5.2.0 graphs (.docx)
5.1.1_vs_5.2.0 graphs (.pdf)
Test that uses Java Request instead of a real website
5.1.1_vs_5.2.0 second test graph (.pdf)

Description pierre.astruc 2019-08-30 20:41:40 UTC
Created attachment 36748 [details]


I found something strange with the number of requests in 5.2.0-SNAPSHOT (81ba16c) versus 5.1.1 (release).

The only modifications of jmeter.properties are:
- httpclient4.retrycount=1
- httpsampler.ignore_failed_embedded_resources=true
- proxy.cert.validity=7000

Please download and play the simpletest.jmx attached with jmeter GUI.
It's one 2 steps test plan with 30 threads and 60 seconds duration.
The test plan only download two pages with auto-download of embedded ressources.
I also added to it 6 live graph with jp@gc plugins.

With 5.1.1 (release), everything is correct, number of transactions/sec is stable at 3, number of responses/sec are stable at 64, bandwidth is stable, and total number of sample is 149.

With 5.2.0 (81ba16c), all is ok until 40 sec, and the test became crazy in the last 20 sec ! the number of transactions/sec grow up from 3 to 14, the number of responses/sec grow up grom 70 to 315, the bytes/sec grow up grom 3MB/s to 10MB/s, and the final number of request is 234 instead of 149.

Every indicators show me that the test is starting to make a lot of requests without any reason.

I will add one second .docx attachement to show you the differences between graphics.

Thanks for reading :)
Comment 1 pierre.astruc 2019-08-30 20:42:28 UTC
Created attachment 36749 [details]
5.1.1_vs_5.2.0 graphs (.docx)
Comment 2 pierre.astruc 2019-08-30 20:54:03 UTC
I just read in another bug report that .doc files were not recommended, sorry I didn't know, so here it the .pdf of same pictures comparaisons
Comment 3 pierre.astruc 2019-08-30 20:55:32 UTC
Created attachment 36751 [details]
5.1.1_vs_5.2.0 graphs (.pdf)
Comment 4 Philippe Mouawad 2019-09-05 20:33:12 UTC
Created attachment 36764 [details]
Test that uses Java Request instead of a real website

I confirm bug which must be related to a regression introduced by Bug 63490
Comment 5 Felix Schumacher 2019-09-07 12:30:25 UTC
The problem here is the Flow Control Action, that uses the changed TimerService. As soon as the delay would be longer than the scheduled test, the delay gets calculated as "-1". That leads to a no-stop action and to the observed high request count.
Comment 6 Felix Schumacher 2019-09-07 13:27:51 UTC
Thanks for the report and the test plan. I think I fixed the problem. Could you try the next nightly (or current trunk) and report back?

commit 3f78a23e4f91e17dde1c3cac86f60b828de36b05
AuthorDate: Sat Sep 7 15:09:58 2019 +0200

    Add more log messages about the delays
    while on the bug 63711 it helped me to debug the error and I think it can be of
    value for others, too. While at it a typo was fixed (looop -> loop) and a bit of
    whitespace was added.
    Bugzilla Id: 63711
 .../java/org/apache/jmeter/sampler/TestAction.java | 23 ++++++++++++++--------
 1 file changed, 15 insertions(+), 8 deletions(-)

commit f2c5260abe7a3e1022793474c0a1e322dd0a2010
AuthorDate: Sat Sep 7 15:20:24 2019 +0200

    Revert behaviour of TimerService#adjustDelay to that of 5.1.1
    Changing the adjustDelay method to return -1 when the delay would be longer
    than the remaining scheduled duration, lead to bug 63711.
    This change reverts the default adjustDelay to the old behaviour and adds a
    flag to enable the "new" feature of returning -1 when the sleep time would
    be too long.
    Bugzilla Id: 63711
 .../org/apache/jmeter/timers/TimerServiceTest.java | 33 +++++++++++++++-
 .../org/apache/jmeter/threads/JMeterThread.java    |  3 +-
 .../org/apache/jmeter/timers/TimerService.java     | 46 +++++++++++++++++++---
 3 files changed, 74 insertions(+), 8 deletions(-)
Comment 7 pierre.astruc 2019-09-09 13:56:07 UTC
Created attachment 36770 [details]
5.1.1_vs_5.2.0 second test graph (.pdf)
Comment 8 pierre.astruc 2019-09-09 13:57:14 UTC
Hello Felix,

Once again, you manage to quickly fix one bug :)
Well done, it's okay for me with 5.2 nightly (bb01309)