Bug 50134 - TransactionController : Reports bad response time when it contains other TransactionControllers
Summary: TransactionController : Reports bad response time when it contains other Tran...
Alias: None
Product: JMeter
Classification: Unclassified
Component: Main (show other bugs)
Version: 2.4
Hardware: All All
: P2 blocker with 1 vote (vote)
Target Milestone: ---
Assignee: JMeter issues mailing list
Depends on:
Reported: 2010-10-21 03:43 UTC by Philippe Mouawad
Modified: 2010-11-01 13:01 UTC (History)
0 users

Screenshot showing bug (115.95 KB, image/png)
2010-10-21 03:43 UTC, Philippe Mouawad
JMX Plan showing issue (21.60 KB, text/plain)
2010-10-21 03:46 UTC, Philippe Mouawad
JSP for test case (139 bytes, text/plain)
2010-10-21 03:48 UTC, Philippe Mouawad
Patch to the bug (1.08 KB, patch)
2010-10-21 03:56 UTC, Philippe Mouawad
Details | Diff
Simpler Test plan (36.92 KB, application/octet-stream)
2010-10-21 10:06 UTC, Philippe Mouawad
Screenshot showing bug with new Java Sampler JMX (104.09 KB, image/png)
2010-10-21 10:07 UTC, Philippe Mouawad
Cleaned up JMX (10.86 KB, application/octet-stream)
2010-10-21 14:39 UTC, Philippe Mouawad
Patch to issue (6.57 KB, patch)
2010-11-01 06:11 UTC, Philippe Mouawad
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Philippe Mouawad 2010-10-21 03:43:56 UTC
Created attachment 26197 [details]
Screenshot showing bug

I have a case where I nested a TransactionController inside another.
See attached test JMX called bug.jmx.
What happens is root TransactionController cumulates times of its insider transaction controller, see attached screenshot.
scenario4 has time of 16124 instead of having 8063.

This issue affects 2.4 and nightly build of 21/10/2010.

I will submit a patch in minutes.
Philippe M.
Comment 1 Philippe Mouawad 2010-10-21 03:46:10 UTC
Created attachment 26198 [details]
JMX Plan showing issue
Comment 2 Philippe Mouawad 2010-10-21 03:48:02 UTC
Created attachment 26199 [details]
JSP for test case

Put this JSP in standard Tomcat 6 inside folder:
Comment 3 Philippe Mouawad 2010-10-21 03:56:51 UTC
Created attachment 26200 [details]
Patch to the bug

This patch corrects the issue.
Comment 4 Philippe Mouawad 2010-10-21 03:58:02 UTC
I submitted the patch, hope you can take it into account soon.

Thank you 
Philippe M.
Comment 5 Sebb 2010-10-21 06:36:58 UTC
Would it be possible to provide a simpler test case using just Java Request samplers?
Comment 6 Philippe Mouawad 2010-10-21 10:06:57 UTC
Created attachment 26201 [details]
Simpler Test plan

Here is a simpler test based on java samplers.

Philippe M.
Comment 7 Philippe Mouawad 2010-10-21 10:07:44 UTC
Created attachment 26202 [details]
Screenshot showing bug with new Java Sampler JMX
Comment 8 Sebb 2010-10-21 11:08:43 UTC
Sorry, but the test plan is still quite difficult to follow, as it has disabled entries and assertions, several thread groups etc.

I've no idea which parts of the plan are relevant.
Time spent fixing the test plan is time that cannot be spent fixing the bug.

Please can you provide the simplest possible plan that shows the problem?
Comment 9 Philippe Mouawad 2010-10-21 12:49:50 UTC
Sorry sebb, You can remove all disabled objects, thé scénario to use is S5.
You run it and in résults you Will see that scénario 5 has wrong response Time it cumulates all its inner response Time even when on transactioncontroller contains another one.
I Can upload new jmx within tomorrow if you really need it.

I submitted thé patch to bug and tested it successfully.

Thank you
Comment 10 Philippe Mouawad 2010-10-21 14:39:02 UTC
Created attachment 26203 [details]
Cleaned up JMX

Sorry It seems I messed up with my JMX, this one is the good one.
Thank you again for your time.

Comment 11 Philippe Mouawad 2010-10-22 08:13:29 UTC
Comment on attachment 26200 [details]
Patch to the bug

Patch is not working.
There is some other case it does not solve.
Comment 12 Philippe Mouawad 2010-11-01 06:11:47 UTC
Created attachment 26245 [details]
Patch to issue

I analyzed a bit more what was happening.
I think I understood where the issue comes from.

As the plan is built, here is how sampleOccured in TransactionController is called:
SampleOccured :s4-1-s1 in :s4-chapeau
SampleOccured :s4-1-s1 in :scenario5
SampleOccured :s4-1-s2 in :s4-chapeau
SampleOccured :s4-1-s2 in :scenario5
SampleOccured :s4-chapeau in :scenario5

This is because scenario5 and s4-chapeau are both registered as listeners for each sample, this end up in the upper most parent recording twice things and mixing up pause time.

In my analysis there are 2 types of SampleEvent:
- One that is initiated by a real Sample
- One that is initiated "artificially" by TransactionController#next2, this one should not be used in computations

So my idea was to distinguish them by an additional attribute called isTransactionSampleEvent.
I use this attribute setting it to true in next2() to build the SampleEvent
and use it in sampleOccured() to use it in computation or not.

I tested with the existing test plan and the one that is a bit more complicated and it works.
But I think you have the big picture to validate this modification.

By the way you will notice some changes in SampleEvent because I made some refactoring in the constructor to make them use each others instead of copy/paste.

Thank you for your time and great product and hope you will have some time to take this patch into account.

Philippe M.
Comment 13 Sebb 2010-11-01 13:01:39 UTC
Yes, I think your analysis is correct, and the patch approach is reasonable.

Applied the fix to SVN with some minor changes:
- dropped unnecessary setTransactionSampleEvent and made boolean final
- made new ctor private, as not used externally
- simplified nested conditional block.
- replaced tabs with spaces, and removed spurious blank lines

URL: http://svn.apache.org/viewvc?rev=1029746&view=rev
Bug 50134 - TransactionController : Reports bad response time when it contains other TransactionControllers