JMeter 线程未终止



我的JMeter在一个有2个内核和512m内存的Docker容器中运行。jmx文件设置有10个并发用户,没有启动时间,测试时间设置为5分钟。我在一个微服务上反复运行这些测试,该微服务对10000个整数列表进行合并排序,以查看不同JVM参数的延迟差异。该微服务还运行在Docker容器上,该容器有2个内核和512m内存。我以前用1000整数列表执行过这个测试,没有遇到任何问题,但当我将整数列表设置为10000时,JMeter测试会出现错误,不会终止线程,也会挂起而不终止执行。

下面显示的是JMeter日志

2020-03-11 08:12:19,244 INFO o.a.j.u.JMeterUtils: Setting Locale to en_EN
2020-03-11 08:12:19,295 INFO o.a.j.JMeter: Loading user properties from: user.properties
2020-03-11 08:12:19,295 INFO o.a.j.JMeter: Loading system properties from: /opt/apache-jmeter-5.2.1/bin/system.properties
2020-03-11 08:12:19,296 INFO o.a.j.JMeter: Loading additional properties from: user.properties
2020-03-11 08:12:19,297 INFO o.a.j.JMeter: Copyright (c) 1998-2019 The Apache Software Foundation
2020-03-11 08:12:19,298 INFO o.a.j.JMeter: Version 5.2.1
2020-03-11 08:12:19,298 INFO o.a.j.JMeter: java.version=1.8.0_212
2020-03-11 08:12:19,298 INFO o.a.j.JMeter: java.vm.name=OpenJDK 64-Bit Server VM
2020-03-11 08:12:19,298 INFO o.a.j.JMeter: os.name=Linux
2020-03-11 08:12:19,298 INFO o.a.j.JMeter: os.arch=amd64
2020-03-11 08:12:19,298 INFO o.a.j.JMeter: os.version=5.3.0-40-generic
2020-03-11 08:12:19,298 INFO o.a.j.JMeter: file.encoding=UTF-8
2020-03-11 08:12:19,298 INFO o.a.j.JMeter: java.awt.headless=null
2020-03-11 08:12:19,299 INFO o.a.j.JMeter: Max memory     =1073741824
2020-03-11 08:12:19,299 INFO o.a.j.JMeter: Available Processors =2
2020-03-11 08:12:19,312 INFO o.a.j.JMeter: Default Locale=English (EN)
2020-03-11 08:12:19,315 INFO o.a.j.JMeter: JMeter  Locale=English (EN)
2020-03-11 08:12:19,315 INFO o.a.j.JMeter: JMeterHome=/opt/apache-jmeter-5.2.1
2020-03-11 08:12:19,316 INFO o.a.j.JMeter: user.dir  =/jmeter
2020-03-11 08:12:19,316 INFO o.a.j.JMeter: PWD       =/jmeter
2020-03-11 08:12:19,316 INFO o.a.j.JMeter: IP: 172.17.0.3 Name: 5ca03afb9c05 FullName: 5ca03afb9c05
2020-03-11 08:12:19,323 INFO o.a.j.s.FileServer: Default base='/jmeter'
2020-03-11 08:12:19,331 INFO o.a.j.s.FileServer: Set new base='/jmeter'
2020-03-11 08:12:19,531 INFO o.a.j.s.SaveService: Testplan (JMX) version: 2.2. Testlog (JTL) version: 2.2
2020-03-11 08:12:19,551 INFO o.a.j.s.SaveService: Using SaveService properties file encoding UTF-8
2020-03-11 08:12:19,569 INFO o.a.j.s.SaveService: Using SaveService properties version 5.0
2020-03-11 08:12:19,593 INFO o.a.j.s.SaveService: Loading file: factorial.jmx
2020-03-11 08:12:19,651 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/html is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
2020-03-11 08:12:19,652 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for application/xhtml+xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
2020-03-11 08:12:19,652 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for application/xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
2020-03-11 08:12:19,652 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
2020-03-11 08:12:19,652 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/vnd.wap.wml is org.apache.jmeter.protocol.http.parser.RegexpHTMLParser
2020-03-11 08:12:19,652 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/css is org.apache.jmeter.protocol.http.parser.CssParser
2020-03-11 08:12:19,663 INFO o.a.j.JMeter: Creating summariser <summary>
2020-03-11 08:12:19,686 INFO o.a.j.e.StandardJMeterEngine: Running the test!
2020-03-11 08:12:19,687 INFO o.a.j.s.SampleEvent: List of sample_variables: []
2020-03-11 08:12:19,687 INFO o.a.j.s.SampleEvent: List of sample_variables: []
2020-03-11 08:12:19,696 INFO o.a.j.e.u.CompoundVariable: Note: Function class names must contain the string: '.functions.'
2020-03-11 08:12:19,696 INFO o.a.j.e.u.CompoundVariable: Note: Function class names must not contain the string: '.gui.'
2020-03-11 08:12:20,228 INFO o.a.j.JMeter: Running test (1583914340228)
2020-03-11 08:12:20,287 INFO o.a.j.e.StandardJMeterEngine: Starting ThreadGroup: 1 : testThread
2020-03-11 08:12:20,287 INFO o.a.j.e.StandardJMeterEngine: Starting 10 threads for group testThread.
2020-03-11 08:12:20,287 INFO o.a.j.e.StandardJMeterEngine: Thread will continue on error
2020-03-11 08:12:20,287 INFO o.a.j.t.ThreadGroup: Starting thread group... number=1 threads=10 ramp-up=0 delayedStart=false
2020-03-11 08:12:20,301 INFO o.a.j.t.JMeterThread: Thread started: testThread 1-1
2020-03-11 08:12:20,309 INFO o.a.j.t.JMeterThread: Thread started: testThread 1-2
2020-03-11 08:12:20,309 INFO o.a.j.t.JMeterThread: Thread started: testThread 1-3
2020-03-11 08:12:20,312 INFO o.a.j.t.JMeterThread: Thread started: testThread 1-4
2020-03-11 08:12:20,327 INFO o.a.j.t.JMeterThread: Thread started: testThread 1-5
2020-03-11 08:12:20,334 INFO o.a.j.t.JMeterThread: Thread started: testThread 1-6
2020-03-11 08:12:20,337 INFO o.a.j.t.JMeterThread: Thread started: testThread 1-7
2020-03-11 08:12:20,340 INFO o.a.j.t.JMeterThread: Thread started: testThread 1-8
2020-03-11 08:12:20,345 INFO o.a.j.p.h.s.HTTPHCAbstractImpl: Local host = 5ca03afb9c05
2020-03-11 08:12:20,343 INFO o.a.j.t.JMeterThread: Thread started: testThread 1-9
2020-03-11 08:12:20,348 INFO o.a.j.t.ThreadGroup: Started thread group number 1
2020-03-11 08:12:20,348 INFO o.a.j.e.StandardJMeterEngine: All thread groups have been started
2020-03-11 08:12:20,350 INFO o.a.j.t.JMeterThread: Thread started: testThread 1-10
2020-03-11 08:12:20,357 INFO o.a.j.p.h.s.HTTPHC4Impl: HTTP request retry count = 0
2020-03-11 08:12:20,359 INFO o.a.j.s.SampleResult: Note: Sample TimeStamps are START times
2020-03-11 08:12:20,360 INFO o.a.j.s.SampleResult: sampleresult.default.encoding is set to ISO-8859-1
2020-03-11 08:12:20,360 INFO o.a.j.s.SampleResult: sampleresult.useNanoTime=true
2020-03-11 08:12:20,360 INFO o.a.j.s.SampleResult: sampleresult.nanoThreadSleep=5000
2020-03-11 08:12:30,018 INFO o.a.j.r.Summariser: summary +   3130 in 00:00:10 =  319.9/s Avg:    27 Min:     0 Max:  2908 Err:  2984 (95.34%) Active: 10 Started: 10 Finished: 0
2020-03-11 08:13:00,005 INFO o.a.j.r.Summariser: summary +    959 in 00:00:30 =   32.0/s Avg:   310 Min:     9 Max:   792 Err:     0 (0.00%) Active: 10 Started: 10 Finished: 0
2020-03-11 08:13:00,008 INFO o.a.j.r.Summariser: summary =   4089 in 00:00:40 =  102.8/s Avg:    93 Min:     0 Max:  2908 Err:  2984 (72.98%)
2020-03-11 08:13:30,003 INFO o.a.j.r.Summariser: summary +    813 in 00:00:30 =   27.1/s Avg:   369 Min:    15 Max:  1096 Err:     0 (0.00%) Active: 10 Started: 10 Finished: 0
2020-03-11 08:13:30,006 INFO o.a.j.r.Summariser: summary =   4902 in 00:01:10 =   70.3/s Avg:   139 Min:     0 Max:  2908 Err:  2984 (60.87%)
2020-03-11 08:14:00,071 INFO o.a.j.r.Summariser: summary +    946 in 00:00:30 =   31.5/s Avg:   317 Min:     7 Max:   993 Err:     0 (0.00%) Active: 10 Started: 10 Finished: 0
2020-03-11 08:14:00,075 INFO o.a.j.r.Summariser: summary =   5848 in 00:01:40 =   58.6/s Avg:   168 Min:     0 Max:  2908 Err:  2984 (51.03%)
2020-03-11 08:14:30,012 INFO o.a.j.r.Summariser: summary +   1140 in 00:00:30 =   38.1/s Avg:   262 Min:     5 Max:  1106 Err:     0 (0.00%) Active: 10 Started: 10 Finished: 0
2020-03-11 08:14:30,015 INFO o.a.j.r.Summariser: summary =   6988 in 00:02:10 =   53.8/s Avg:   183 Min:     0 Max:  2908 Err:  2984 (42.70%)
2020-03-11 08:15:00,009 INFO o.a.j.r.Summariser: summary +    671 in 00:00:30 =   22.4/s Avg:   446 Min:    11 Max:  1100 Err:     0 (0.00%) Active: 10 Started: 10 Finished: 0
2020-03-11 08:15:00,011 INFO o.a.j.r.Summariser: summary =   7659 in 00:02:40 =   47.9/s Avg:   206 Min:     0 Max:  2908 Err:  2984 (38.96%)
2020-03-11 08:15:30,019 INFO o.a.j.r.Summariser: summary +    621 in 00:00:30 =   20.7/s Avg:   483 Min:    13 Max:  1236 Err:     0 (0.00%) Active: 10 Started: 10 Finished: 0
2020-03-11 08:15:30,021 INFO o.a.j.r.Summariser: summary =   8280 in 00:03:10 =   43.6/s Avg:   227 Min:     0 Max:  2908 Err:  2984 (36.04%)
2020-03-11 08:16:00,007 INFO o.a.j.r.Summariser: summary +    759 in 00:00:30 =   25.3/s Avg:   393 Min:    15 Max:   900 Err:     0 (0.00%) Active: 10 Started: 10 Finished: 0
2020-03-11 08:16:00,011 INFO o.a.j.r.Summariser: summary =   9039 in 00:03:40 =   41.1/s Avg:   241 Min:     0 Max:  2908 Err:  2984 (33.01%)
2020-03-11 08:16:30,180 INFO o.a.j.r.Summariser: summary +   1008 in 00:00:30 =   33.5/s Avg:   298 Min:     5 Max:   976 Err:     0 (0.00%) Active: 10 Started: 10 Finished: 0
2020-03-11 08:16:30,218 INFO o.a.j.r.Summariser: summary =  10047 in 00:04:10 =   40.2/s Avg:   247 Min:     0 Max:  2908 Err:  2984 (29.70%)
2020-03-11 08:17:00,076 INFO o.a.j.r.Summariser: summary +    715 in 00:00:30 =   23.9/s Avg:   415 Min:    10 Max:  1117 Err:     0 (0.00%) Active: 10 Started: 10 Finished: 0
2020-03-11 08:17:00,091 INFO o.a.j.r.Summariser: summary =  10762 in 00:04:40 =   38.5/s Avg:   258 Min:     0 Max:  2908 Err:  2984 (27.73%)
2020-03-11 08:17:20,405 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: testThread 1-7
2020-03-11 08:17:20,407 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: testThread 1-10
2020-03-11 08:17:20,412 INFO o.a.j.t.JMeterThread: Thread finished: testThread 1-7
2020-03-11 08:17:20,412 INFO o.a.j.t.JMeterThread: Thread finished: testThread 1-10
2020-03-11 08:17:20,495 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: testThread 1-6
2020-03-11 08:17:20,496 INFO o.a.j.t.JMeterThread: Thread finished: testThread 1-6
2020-03-11 08:17:20,528 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: testThread 1-3
2020-03-11 08:17:20,550 INFO o.a.j.t.JMeterThread: Thread finished: testThread 1-3
2020-03-11 08:17:20,567 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: testThread 1-9
2020-03-11 08:17:20,567 INFO o.a.j.t.JMeterThread: Thread finished: testThread 1-9
2020-03-11 08:17:20,578 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: testThread 1-5
2020-03-11 08:17:20,578 INFO o.a.j.t.JMeterThread: Thread finished: testThread 1-5
2020-03-11 08:17:20,583 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: testThread 1-1
2020-03-11 08:17:20,583 INFO o.a.j.t.JMeterThread: Thread finished: testThread 1-1
2020-03-11 08:17:20,589 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: testThread 1-4
2020-03-11 08:17:20,590 INFO o.a.j.t.JMeterThread: Thread finished: testThread 1-4
2020-03-11 08:17:20,604 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: testThread 1-8
2020-03-11 08:17:20,604 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: testThread 1-2
2020-03-11 08:17:20,605 INFO o.a.j.t.JMeterThread: Thread finished: testThread 1-2
2020-03-11 08:17:20,605 INFO o.a.j.t.JMeterThread: Thread finished: testThread 1-8
2020-03-11 08:17:20,931 INFO o.a.j.e.StandardJMeterEngine: Notifying test listeners of end of test

我在这里做错什么了吗?如何消除这些错误?

我在JMeter日志文件中没有看到任何异常行为。

如果你的问题是关于2984个失败的请求,那么它没有提供足够的失败原因信息。

  1. 检查.jtl结果文件,通常它包含HTTP响应状态代码和消息,这些代码和消息可能会揭示失败的原因
  2. 检查应用程序日志
  3. 您可以通过向user.properties文件添加下一行来临时配置JMeter以保存完整的响应数据:

    jmeter.save.saveservice.output_format=xml
    jmeter.save.saveservice.response_data.on_error=true
    

    通过这种方式,您将在.jtl结果文件中获得完整的响应,这样您就可以确定应用程序过载时最终用户会得到什么错误。

最新更新