Bug 61254 - Summariser : Active thread count in is not correct during high load distributing test when using statistical mode
Summary: Summariser : Active thread count in is not correct during high load distribut...
Status: NEW
Alias: None
Product: JMeter
Classification: Unclassified
Component: Main (show other bugs)
Version: 3.1
Hardware: PC All
: P2 normal (vote)
Target Milestone: ---
Assignee: JMeter issues mailing list
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-07-06 01:51 UTC by Liu XP
Modified: 2017-07-24 03:34 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 2017-07-06 01:51:30 UTC
1. Start JMeter distributing test with statistical mode(used 60 JMeter servers and each instance start with 5000 threads).
2. After finished test, I checked the jmeter.log file and found the active thread count[29,8199] is less than expect number[60*5000=300,000].

The below is part of logs:
...
2017/06/30 11:16:59 INFO  - jmeter.engine.ClientJMeterEngine: sent test to 172.18.50.171 basedir='jmeter' 
2017/06/30 11:16:59 INFO  - jmeter.engine.ClientJMeterEngine: Sending properties {sServerIP=172.18.2.11, nSize=1, nThreadNum=5000, nRampUp=5, nSleepTimes=0.25, nDuration=300} 
2017/06/30 11:16:59 INFO  - jmeter.engine.ClientJMeterEngine: sent run command to 172.18.50.171 
2017/06/30 11:16:59 INFO  - jmeter.engine.DistributedRunner: Remote engines have been started 
2017/06/30 11:16:59 INFO  - jmeter.JMeter: Started remote host:  172.18.50.171 (1498792619927) 
2017/06/30 11:17:01 INFO  - jmeter.reporters.Summariser: summary + 1170057 in 00:00:06 = 209088.1/s Avg:   267 Min:   248 Max:  1386 Err:     0 (0.0000%) Active: 161508 Started: 47672 Finished: 0
2017/06/30 11:17:01 INFO  - jmeter.reporters.Summariser: summary = 1170058 in 00:00:06 = 197211.9/s Avg:   267 Min:   248 Max:  1386 Err:     0 (0.0000%)
2017/06/30 11:17:10 INFO  - jmeter.reporters.Summariser: summary + 7412000 in 00:00:09 = 823372.6/s Avg:   317 Min:   224 Max:  2064 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:17:10 INFO  - jmeter.reporters.Summariser: summary = 8582058 in 00:00:15 = 574588.8/s Avg:   310 Min:   224 Max:  2064 Err:     0 (0.0000%)
2017/06/30 11:17:20 INFO  - jmeter.reporters.Summariser: summary + 8955000 in 00:00:10 = 895768.7/s Avg:   330 Min:   223 Max:  1753 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:17:20 INFO  - jmeter.reporters.Summariser: summary = 17537058 in 00:00:25 = 703367.3/s Avg:   321 Min:   223 Max:  2064 Err:     0 (0.0000%)
2017/06/30 11:17:30 INFO  - jmeter.reporters.Summariser: summary + 8486000 in 00:00:10 = 848515.1/s Avg:   347 Min:    85 Max:  2167 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:17:30 INFO  - jmeter.reporters.Summariser: summary = 26023058 in 00:00:35 = 744920.7/s Avg:   329 Min:    85 Max:  2167 Err:     0 (0.0000%)
2017/06/30 11:17:40 INFO  - jmeter.reporters.Summariser: summary + 8964000 in 00:00:10 = 896489.6/s Avg:   331 Min:   224 Max:  2038 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:17:40 INFO  - jmeter.reporters.Summariser: summary = 34987058 in 00:00:45 = 778649.5/s Avg:   330 Min:    85 Max:  2167 Err:     0 (0.0000%)
2017/06/30 11:17:50 INFO  - jmeter.reporters.Summariser: summary + 8988000 in 00:00:10 = 898530.4/s Avg:   331 Min:   218 Max:  1444 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:17:50 INFO  - jmeter.reporters.Summariser: summary = 43975058 in 00:00:55 = 800478.0/s Avg:   330 Min:    85 Max:  2167 Err:     0 (0.0000%)
2017/06/30 11:18:00 INFO  - jmeter.reporters.Summariser: summary + 8931000 in 00:00:10 = 893368.0/s Avg:   332 Min:   114 Max:  1636 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:18:00 INFO  - jmeter.reporters.Summariser: summary = 52906058 in 00:01:05 = 814779.2/s Avg:   330 Min:    85 Max:  2167 Err:     0 (0.0000%)
2017/06/30 11:18:10 INFO  - jmeter.reporters.Summariser: summary + 8900000 in 00:00:10 = 889911.0/s Avg:   333 Min:    76 Max:  1871 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:18:10 INFO  - jmeter.reporters.Summariser: summary = 61806058 in 00:01:15 = 824806.6/s Avg:   331 Min:    76 Max:  2167 Err:     0 (0.0000%)
2017/06/30 11:18:20 INFO  - jmeter.reporters.Summariser: summary + 8943000 in 00:00:10 = 894389.4/s Avg:   332 Min:   224 Max:  1457 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:18:20 INFO  - jmeter.reporters.Summariser: summary = 70749058 in 00:01:25 = 832998.5/s Avg:   331 Min:    76 Max:  2167 Err:     0 (0.0000%)
2017/06/30 11:18:30 INFO  - jmeter.reporters.Summariser: summary + 8931000 in 00:00:10 = 893010.7/s Avg:   333 Min:   107 Max:  2363 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:18:30 INFO  - jmeter.reporters.Summariser: summary = 79680058 in 00:01:35 = 839320.6/s Avg:   331 Min:    76 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:18:40 INFO  - jmeter.reporters.Summariser: summary + 8899000 in 00:00:10 = 889811.0/s Avg:   334 Min:    50 Max:  1758 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:18:40 INFO  - jmeter.reporters.Summariser: summary = 88579058 in 00:01:45 = 844132.6/s Avg:   331 Min:    50 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:18:50 INFO  - jmeter.reporters.Summariser: summary + 8870000 in 00:00:10 = 887177.4/s Avg:   334 Min:   230 Max:  1659 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:18:50 INFO  - jmeter.reporters.Summariser: summary = 97449058 in 00:01:55 = 847862.3/s Avg:   332 Min:    50 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:19:00 INFO  - jmeter.reporters.Summariser: summary + 8892000 in 00:00:10 = 889377.9/s Avg:   332 Min:    37 Max:  1954 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:19:00 INFO  - jmeter.reporters.Summariser: summary = 106341058 in 00:02:05 = 851184.7/s Avg:   332 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:19:10 INFO  - jmeter.reporters.Summariser: summary + 8868000 in 00:00:10 = 886711.3/s Avg:   336 Min:    46 Max:  2089 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:19:10 INFO  - jmeter.reporters.Summariser: summary = 115209058 in 00:02:15 = 853817.9/s Avg:   332 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:19:20 INFO  - jmeter.reporters.Summariser: summary + 8871000 in 00:00:10 = 887100.0/s Avg:   334 Min:   215 Max:  1830 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:19:20 INFO  - jmeter.reporters.Summariser: summary = 124080058 in 00:02:25 = 856114.2/s Avg:   332 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:19:30 INFO  - jmeter.reporters.Summariser: summary + 8809000 in 00:00:10 = 880900.0/s Avg:   337 Min:    54 Max:  1679 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:19:30 INFO  - jmeter.reporters.Summariser: summary = 132889058 in 00:02:35 = 857714.0/s Avg:   332 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:19:40 INFO  - jmeter.reporters.Summariser: summary + 8858000 in 00:00:10 = 885800.0/s Avg:   336 Min:    62 Max:  1822 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:19:40 INFO  - jmeter.reporters.Summariser: summary = 141747058 in 00:02:45 = 859416.8/s Avg:   333 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:19:50 INFO  - jmeter.reporters.Summariser: summary + 8849000 in 00:00:10 = 884900.0/s Avg:   334 Min:   223 Max:  1850 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:19:50 INFO  - jmeter.reporters.Summariser: summary = 150596058 in 00:02:55 = 860873.6/s Avg:   333 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:20:00 INFO  - jmeter.reporters.Summariser: summary + 8843000 in 00:00:10 = 884388.4/s Avg:   335 Min:   103 Max:  2088 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:20:00 INFO  - jmeter.reporters.Summariser: summary = 159439058 in 00:03:05 = 862145.0/s Avg:   333 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:20:10 INFO  - jmeter.reporters.Summariser: summary + 8812000 in 00:00:10 = 881200.0/s Avg:   337 Min:    84 Max:  1756 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:20:10 INFO  - jmeter.reporters.Summariser: summary = 168251058 in 00:03:15 = 863118.1/s Avg:   333 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:20:20 INFO  - jmeter.reporters.Summariser: summary + 8785000 in 00:00:10 = 878587.9/s Avg:   338 Min:   224 Max:  2063 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:20:20 INFO  - jmeter.reporters.Summariser: summary = 177036058 in 00:03:25 = 863872.9/s Avg:   333 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:20:30 INFO  - jmeter.reporters.Summariser: summary + 8809000 in 00:00:10 = 880900.0/s Avg:   336 Min:   140 Max:  1864 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:20:30 INFO  - jmeter.reporters.Summariser: summary = 185845058 in 00:03:35 = 864665.1/s Avg:   333 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:20:40 INFO  - jmeter.reporters.Summariser: summary + 8812000 in 00:00:10 = 881200.0/s Avg:   337 Min:    67 Max:  1915 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:20:40 INFO  - jmeter.reporters.Summariser: summary = 194657058 in 00:03:45 = 865400.2/s Avg:   334 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:20:50 INFO  - jmeter.reporters.Summariser: summary + 8862000 in 00:00:10 = 886111.4/s Avg:   335 Min:   203 Max:  1793 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:20:50 INFO  - jmeter.reporters.Summariser: summary = 203519058 in 00:03:55 = 866281.8/s Avg:   334 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:21:00 INFO  - jmeter.reporters.Summariser: summary + 8848000 in 00:00:10 = 884888.5/s Avg:   335 Min:   189 Max:  1575 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:21:00 INFO  - jmeter.reporters.Summariser: summary = 212367058 in 00:04:05 = 867041.4/s Avg:   334 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:21:10 INFO  - jmeter.reporters.Summariser: summary + 8790000 in 00:00:10 = 879000.0/s Avg:   336 Min:   103 Max:  1823 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:21:10 INFO  - jmeter.reporters.Summariser: summary = 221157058 in 00:04:15 = 867510.5/s Avg:   334 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:21:20 INFO  - jmeter.reporters.Summariser: summary + 8810000 in 00:00:10 = 880911.9/s Avg:   336 Min:   182 Max:  2116 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:21:20 INFO  - jmeter.reporters.Summariser: summary = 229967058 in 00:04:25 = 868016.4/s Avg:   334 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:21:30 INFO  - jmeter.reporters.Summariser: summary + 8784000 in 00:00:10 = 878400.0/s Avg:   338 Min:    46 Max:  1805 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:21:30 INFO  - jmeter.reporters.Summariser: summary = 238751058 in 00:04:35 = 868390.9/s Avg:   334 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:21:40 INFO  - jmeter.reporters.Summariser: summary + 8857000 in 00:00:10 = 885700.0/s Avg:   336 Min:    46 Max:  1880 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:21:40 INFO  - jmeter.reporters.Summariser: summary = 247608058 in 00:04:45 = 868998.4/s Avg:   334 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:21:50 INFO  - jmeter.reporters.Summariser: summary + 8868000 in 00:00:10 = 886888.7/s Avg:   334 Min:   120 Max:  1751 Err:     0 (0.0000%) Active: 298199 Started: 184363 Finished: 0
2017/06/30 11:21:50 INFO  - jmeter.reporters.Summariser: summary = 256476058 in 00:04:55 = 869604.9/s Avg:   334 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:21:59 INFO  - jmeter.JMeter: Finished remote host: 172.18.51.2 (1498792919164) 
2017/06/30 11:22:00 INFO  - jmeter.reporters.Summariser: summary + 6522285 in 00:00:10 = 652032.9/s Avg:   338 Min:   221 Max:  1924 Err:     0 (0.0000%) Active: 122961 Started: 184363 Finished: 175238
2017/06/30 11:22:00 INFO  - jmeter.reporters.Summariser: summary = 262998343 in 00:05:05 = 862467.8/s Avg:   334 Min:    37 Max:  2363 Err:     0 (0.0000%)
2017/06/30 11:22:01 INFO  - jmeter.JMeter: Finished remote host: 172.16.206.218 (1498792921307) 
2017/06/30 11:22:02 INFO  - jmeter.JMeter: Finished remote host: 172.16.206.242 (1498792922004) 
...
Comment 1 Philippe Mouawad 2017-07-16 13:57:47 UTC
Hello,
Thanks for report.
Can you test with default mode (MODE_STRIPPED_BATCH)  StrippedAsynch.

Thank you
Comment 2 Liu XP 2017-07-21 07:16:47 UTC
When used default mode (MODE_STRIPPED_BATCH)  StrippedAsynch, it will used up network bandwith on JMeter client side and the count of active thread number also not correct.

The below is part of logs:

2017/07/21 15:03:04 INFO  - jmeter.samplers.BatchSampleSender: Using batching (client settings) for this run. Thresholds: num=100, time=5000 
2017/07/21 15:03:04 INFO  - jmeter.samplers.DataStrippingSampleSender: Using DataStrippingSampleSender for this run 
2017/07/21 15:03:04 INFO  - jmeter.JMeter: Started remote host:  172.18.50.184 (1500620584062) 
2017/07/21 15:03:04 INFO  - jmeter.engine.ClientJMeterEngine: sent test to 172.18.51.15 basedir='.' 
2017/07/21 15:03:04 INFO  - jmeter.engine.ClientJMeterEngine: Sending properties {sServerIP=172.18.2.11, nSize=1, nThreadNum=5000, nRampUp=5, nSleepTimes=0.25, nDuration=180} 
2017/07/21 15:03:04 INFO  - jmeter.engine.ClientJMeterEngine: sent run command to 172.18.51.15 
2017/07/21 15:03:04 INFO  - jmeter.engine.DistributedRunner: Remote engines have been started 
2017/07/21 15:03:04 INFO  - jmeter.JMeter: Started remote host:  172.18.51.15 (1500620584200) 
2017/07/21 15:03:10 INFO  - jmeter.reporters.Summariser: summary +  13592 in 00:00:06 = 2229.3/s Avg:   261 Min:   249 Max:   612 Err:     0 (0.0000%) Active: 29318 Started: 26887 Finished: 0
2017/07/21 15:03:10 INFO  - jmeter.reporters.Summariser: summary =  13593 in 00:00:07 = 2064.2/s Avg:   261 Min:   249 Max:   612 Err:     0 (0.0000%)
2017/07/21 15:03:21 INFO  - jmeter.reporters.Summariser: summary +  22202 in 00:00:12 = 1874.2/s Avg:   295 Min:   249 Max:   962 Err:     0 (0.0000%) Active: 33402 Started: 30971 Finished: 0
2017/07/21 15:03:21 INFO  - jmeter.reporters.Summariser: summary =  35795 in 00:00:18 = 1942.1/s Avg:   282 Min:   249 Max:   962 Err:     0 (0.0000%)
2017/07/21 15:03:31 INFO  - jmeter.reporters.Summariser: summary +   7254 in 00:00:10 =  730.0/s Avg:   309 Min:   249 Max:   950 Err:     0 (0.0000%) Active: 33402 Started: 30971 Finished: 0
2017/07/21 15:03:31 INFO  - jmeter.reporters.Summariser: summary =  43049 in 00:00:28 = 1517.4/s Avg:   287 Min:   249 Max:   962 Err:     0 (0.0000%)
2017/07/21 15:03:43 INFO  - jmeter.reporters.Summariser: summary +   2184 in 00:00:11 =  191.2/s Avg:   291 Min:   250 Max:   712 Err:     0 (0.0000%) Active: 33402 Started: 30971 Finished: 0
2017/07/21 15:03:43 INFO  - jmeter.reporters.Summariser: summary =  45233 in 00:00:40 = 1136.7/s Avg:   287 Min:   249 Max:   962 Err:     0 (0.0000%)
2017/07/21 15:04:00 INFO  - jmeter.reporters.Summariser: summary +   2233 in 00:00:17 =  130.3/s Avg:   295 Min:   250 Max:   633 Err:     0 (0.0000%) Active: 33402 Started: 30971 Finished: 0
2017/07/21 15:04:00 INFO  - jmeter.reporters.Summariser: summary =  47466 in 00:00:57 =  833.6/s Avg:   287 Min:   249 Max:   962 Err:     0 (0.0000%)
...
Comment 3 Philippe Mouawad 2017-07-22 13:12:59 UTC
Hello, 
So for your last test, your issue looks to me like a consequence of a saturated network right ? 

For initial test, did you check that network between jmeter servers and client is not saturated ?

Did you add a unique ID to Thread Group names of each thread ?
Comment 4 Liu XP 2017-07-24 03:34:35 UTC
So for your last test, your issue looks to me like a consequence of a saturated network right ? 
Yes.

For initial test, did you check that network between jmeter servers and client is not saturated ?
I had checked network bandwith in initial test. The network between jmeter servers and client is not saturated because I used Statistical mode and set num_sample_threshold=1000 to reduce network bandwidth.

Did you add a unique ID to Thread Group names of each thread ?
I hadn't added unique ID to Thread Group name because I don't know where to trace them with Statistical mode.