You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@jmeter.apache.org by Stuart Kenworthy <St...@bjss.com> on 2017/02/13 12:30:03 UTC
Unusually high thread group startup time in jmeter 2.13.
I am seeing some odd behaviour when running a single jmeter script in which contains multiple thread groups that I want to use concurrently.
I am using a distributed setup where the master is controlling 4 slaves. Master and slaves are running on
Ubuntu Server 14.04
openJDK Java version 7u79 also upgraded to 8u92
JMeter version 2.13 r1665067 with xms and xmx set to 16gb
However I get the same behaviour when running locally.
The scripts consist of 1 setup thread group, 3 active thread groups and 2 disabled thread groups which contain shared scripts to be called using module controllers, I have also moved the shared scripts so each thread group has it's own copy of the ones they need.
The 3 active thread groups define the number of threads using:
${__P(g1threads,0)}
${__P(g2threads,0)}
${__P(g3threads,0)}
Groups 1 and 2 has a 10 minute rampup, group 3 has a 2 minute rampup.
I then start the script using:
jmeter -n -t <scriptname> -Gg1threads=4000 =Gg2threads=1000
This should start group 1 with 4000 threads per slave and group 2 with 1000 per slave, group 3 has nothing to start.
This process works fine when only defining the thread counts for 1 group but when I add multiple groups (as the above example) there is a delay in subsequent groups being started as well as an unacceptable lag in any 1 thread group starting. The jmeter-server log shows the following activity:
2017/01/31 14:32:15 INFO - jmeter.threads.ThreadGroup: Starting thread group number 1 threads 1 ramp-up 1 perThread 1000.0 delayedStart=false
2017/01/31 14:33:50 INFO - jmeter.threads.ThreadGroup: Starting thread group number 1 threads 4000 ramp-up 600 perThread 150.0 delayedStart=false
2017/01/31 14:41:37 INFO - jmeter.threads.ThreadGroup: Started thread group number 1
2017/01/31 14:41:37 INFO - jmeter.threads.ThreadGroup: Starting thread group number 2 threads 1000 ramp-up 600 perThread 600.0 delayedStart=false
2017/01/31 14:44:10 INFO - jmeter.threads.ThreadGroup: Started thread group number 2
2017/01/31 14:44:10 INFO - jmeter.threads.ThreadGroup: Starting thread group number 3 threads 0 ramp-up 120 perThread Infinity delayedStart=false
2017/01/31 14:44:10 INFO - jmeter.threads.ThreadGroup: Started thread group number 3
We can see the startup threadgroup starting at 14:32:15 which also creates a load of data files and takes 1 1/2 minutes to do so, this is expected. Active thread group 1 then starts at 14:33:50 and active thread group 2 then starts 8 minutes later as thread group 1 finishes startup.
I need group 2 to start at the same time as group 1 but aware there is an existing bug associated with this (https://bz.apache.org/bugzilla/show_bug.cgi?id=58182) so my problem is squarely focussed on the time the thread group is starting up. I also see for group 1 that the startup time is not 10 minutes, but closer to 15 which points to this 8 minute group startup being the problem.
Thread debug logging has shown nothing up of interest, just many many entries of the below
Subtracting node, stack size = 6
adding controller: org.apache.jmeter.control.LoopController@5f41cacd to sampler config
A simple script
If I do simplify the first thread group to only contain a single sampler, the error does not fully replicate itself but there is a 22 second delay instead of 8 minutes but I would still think this too long for a single sampler script.
2017/01/31 15:38:42 INFO - jmeter.threads.ThreadGroup: Starting thread group number 1 threads 1 ramp-up 1 perThread 1000.0 delayedStart=false
2017/01/31 15:38:42 INFO - jmeter.threads.ThreadGroup: Started thread group number 1
2017/01/31 15:40:21 INFO - jmeter.threads.ThreadGroup: Starting thread group number 1 threads 4000 ramp-up 600 perThread 150.0 delayedStart=false
2017/01/31 15:40:43 INFO - jmeter.threads.ThreadGroup: Started thread group number 1
2017/01/31 15:40:43 INFO - jmeter.threads.ThreadGroup: Starting thread group number 2 threads 1000 ramp-up 600 perThread 600.0 delayedStart=false
I have also tried this with the thread numbers hard coded instead of the parameter and changed the order of the thread groups, the second one always needs to wait until the first one is fully started and the group always takes longer than expected to start.
Playing with "delay thread creation"
I decided to have a play around with the "delay thread creation" option so I enabled this setting in thread group 1 only and it seems to be working on some level but on another level made it much worse.
I can now start up threads on both groups (just a reminder, both groups have a 10 minute ramp up, group 1 has 4000 threads, group 2 has 1000 per box). After 14 minutes it had only been able to start 983 threads out of 4000. Thread group 2 had started 132 out of 1000 and group 1 had started 851 out of 4000.
Using the "Delay" option, instead of it taking 8 minutes to start thread group 1 and 3 minutes to start thread group 2, it took 14 minutes to only start around a quarter of the required threads for both.
Has anyone seen similar issues before and is there an explanation and preferably a workaround for it.
Thanks
The information included in this email and any files transmitted with it may contain information that is confidential and it must not be used by, or its contents or attachments copied or disclosed to, persons other than the intended addressee. If you have received this email in error, please notify BJSS. In the absence of written agreement to the contrary BJSS' relevant standard terms of contract for any work to be undertaken will apply. Please carry out virus or such other checks as you consider appropriate in respect of this email. BJSS does not accept responsibility for any adverse effect upon your system or data in relation to this email or any files transmitted with it. BJSS Limited, a company registered in England and Wales (Company Number 2777575), VAT Registration Number 613295452, Registered Office Address, First Floor, Coronet House, Queen Street, Leeds, LS1 2TW.
RE: Unusually high thread group startup time in jmeter 2.13.
Posted by Stuart Kenworthy <St...@bjss.com>.
Actually, is it possible that I am in part suffering from this bug?
https://bz.apache.org/bugzilla/show_bug.cgi?id=58183
as well as 58182? (it can't be pure co-incidence they are one after the other).
It does not get round my problem but kind of explains why I am having the problem. I effectively need to calculate my ramp-up time based on
((required ramp-up time / number of threads) - start-up time per thread) * number of thread
This can be calculated in a custom jmeter startup shell script, which I already use to ensure I get a 10 minute ramp-up, however it does not address the issue of it taking 8 minutes to allocate thread resource.
Thanks
-----Original Message-----
From: Stuart Kenworthy [mailto:Stuart.Kenworthy@bjss.com]
Sent: 13 February 2017 12:30
To: user@jmeter.apache.org
Subject: Unusually high thread group startup time in jmeter 2.13.
I am seeing some odd behaviour when running a single jmeter script in which contains multiple thread groups that I want to use concurrently.
I am using a distributed setup where the master is controlling 4 slaves. Master and slaves are running on
Ubuntu Server 14.04
openJDK Java version 7u79 also upgraded to 8u92 JMeter version 2.13 r1665067 with xms and xmx set to 16gb
However I get the same behaviour when running locally.
The scripts consist of 1 setup thread group, 3 active thread groups and 2 disabled thread groups which contain shared scripts to be called using module controllers, I have also moved the shared scripts so each thread group has it's own copy of the ones they need.
The 3 active thread groups define the number of threads using:
${__P(g1threads,0)}
${__P(g2threads,0)}
${__P(g3threads,0)}
Groups 1 and 2 has a 10 minute rampup, group 3 has a 2 minute rampup.
I then start the script using:
jmeter -n -t <scriptname> -Gg1threads=4000 =Gg2threads=1000
This should start group 1 with 4000 threads per slave and group 2 with 1000 per slave, group 3 has nothing to start.
This process works fine when only defining the thread counts for 1 group but when I add multiple groups (as the above example) there is a delay in subsequent groups being started as well as an unacceptable lag in any 1 thread group starting. The jmeter-server log shows the following activity:
2017/01/31 14:32:15 INFO - jmeter.threads.ThreadGroup: Starting thread group number 1 threads 1 ramp-up 1 perThread 1000.0 delayedStart=false
2017/01/31 14:33:50 INFO - jmeter.threads.ThreadGroup: Starting thread group number 1 threads 4000 ramp-up 600 perThread 150.0 delayedStart=false
2017/01/31 14:41:37 INFO - jmeter.threads.ThreadGroup: Started thread group number 1
2017/01/31 14:41:37 INFO - jmeter.threads.ThreadGroup: Starting thread group number 2 threads 1000 ramp-up 600 perThread 600.0 delayedStart=false
2017/01/31 14:44:10 INFO - jmeter.threads.ThreadGroup: Started thread group number 2
2017/01/31 14:44:10 INFO - jmeter.threads.ThreadGroup: Starting thread group number 3 threads 0 ramp-up 120 perThread Infinity delayedStart=false
2017/01/31 14:44:10 INFO - jmeter.threads.ThreadGroup: Started thread group number 3
We can see the startup threadgroup starting at 14:32:15 which also creates a load of data files and takes 1 1/2 minutes to do so, this is expected. Active thread group 1 then starts at 14:33:50 and active thread group 2 then starts 8 minutes later as thread group 1 finishes startup.
I need group 2 to start at the same time as group 1 but aware there is an existing bug associated with this (https://bz.apache.org/bugzilla/show_bug.cgi?id=58182) so my problem is squarely focussed on the time the thread group is starting up. I also see for group 1 that the startup time is not 10 minutes, but closer to 15 which points to this 8 minute group startup being the problem.
Thread debug logging has shown nothing up of interest, just many many entries of the below
Subtracting node, stack size = 6
adding controller: org.apache.jmeter.control.LoopController@5f41cacd to sampler config
A simple script
If I do simplify the first thread group to only contain a single sampler, the error does not fully replicate itself but there is a 22 second delay instead of 8 minutes but I would still think this too long for a single sampler script.
2017/01/31 15:38:42 INFO - jmeter.threads.ThreadGroup: Starting thread group number 1 threads 1 ramp-up 1 perThread 1000.0 delayedStart=false
2017/01/31 15:38:42 INFO - jmeter.threads.ThreadGroup: Started thread group number 1
2017/01/31 15:40:21 INFO - jmeter.threads.ThreadGroup: Starting thread group number 1 threads 4000 ramp-up 600 perThread 150.0 delayedStart=false
2017/01/31 15:40:43 INFO - jmeter.threads.ThreadGroup: Started thread group number 1
2017/01/31 15:40:43 INFO - jmeter.threads.ThreadGroup: Starting thread group number 2 threads 1000 ramp-up 600 perThread 600.0 delayedStart=false
I have also tried this with the thread numbers hard coded instead of the parameter and changed the order of the thread groups, the second one always needs to wait until the first one is fully started and the group always takes longer than expected to start.
Playing with "delay thread creation"
I decided to have a play around with the "delay thread creation" option so I enabled this setting in thread group 1 only and it seems to be working on some level but on another level made it much worse.
I can now start up threads on both groups (just a reminder, both groups have a 10 minute ramp up, group 1 has 4000 threads, group 2 has 1000 per box). After 14 minutes it had only been able to start 983 threads out of 4000. Thread group 2 had started 132 out of 1000 and group 1 had started 851 out of 4000.
Using the "Delay" option, instead of it taking 8 minutes to start thread group 1 and 3 minutes to start thread group 2, it took 14 minutes to only start around a quarter of the required threads for both.
Has anyone seen similar issues before and is there an explanation and preferably a workaround for it.
Thanks
The information included in this email and any files transmitted with it may contain information that is confidential and it must not be used by, or its contents or attachments copied or disclosed to, persons other than the intended addressee. If you have received this email in error, please notify BJSS. In the absence of written agreement to the contrary BJSS' relevant standard terms of contract for any work to be undertaken will apply. Please carry out virus or such other checks as you consider appropriate in respect of this email. BJSS does not accept responsibility for any adverse effect upon your system or data in relation to this email or any files transmitted with it. BJSS Limited, a company registered in England and Wales (Company Number 2777575), VAT Registration Number 613295452, Registered Office Address, First Floor, Coronet House, Queen Street, Leeds, LS1 2TW.
The information included in this email and any files transmitted with it may contain information that is confidential and it must not be used by, or its contents or attachments copied or disclosed to, persons other than the intended addressee. If you have received this email in error, please notify BJSS. In the absence of written agreement to the contrary BJSS' relevant standard terms of contract for any work to be undertaken will apply. Please carry out virus or such other checks as you consider appropriate in respect of this email. BJSS does not accept responsibility for any adverse effect upon your system or data in relation to this email or any files transmitted with it. BJSS Limited, a company registered in England and Wales (Company Number 2777575), VAT Registration Number 613295452, Registered Office Address, First Floor, Coronet House, Queen Street, Leeds, LS1 2TW.
---------------------------------------------------------------------
To unsubscribe, e-mail: user-unsubscribe@jmeter.apache.org
For additional commands, e-mail: user-help@jmeter.apache.org