Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Distributed tests only run once #67

Closed
johrstrom opened this issue Oct 16, 2019 · 12 comments
Closed

Distributed tests only run once #67

johrstrom opened this issue Oct 16, 2019 · 12 comments
Assignees
Labels

Comments

@johrstrom
Copy link
Owner

Originally posted in #62. I'm moving it here because it seems to be a whole new thing and possibly a bug in this library. Originally opened there by @jrodguitar.

I setup the jmeter distributed, and prometheus and my pods (which I'm going to test some load against).
Prometheus shows the endpoints as DOWN, before i run any tests.
Prometheus shows the endpoints as UP, while the jmeter tests are running
When the jmeter tests finish, Prometheus shows the endpoints as DOWN.
Up to this point everything is fine.

If i want to do another run of the distributed jmeter, the endpoints never become UP anymore.
even doing a curl localhost:9270 in the pod, seems unreachable.
but running this command kubectl describe endpoints jmeter-slaves-svc
shows that the port 9270 is properly listed.

Any ideas?
The workaround is to redeploy over and over my jmeter slaves pods. but that's not ideal.
@johrstrom
Copy link
Owner Author

First I think we need to rule out if the controlling master instance is not starting the second test on the minion servers.

If it is indeed starting the second test on the minion servers, then we should see some errors about the http server not starting up?

You can increase the log of this library by adding this Logger to your log4j2.xml of the minion servers<Logger name="org.github.johrstrom" level="debug" />.

@jrodguitar
Copy link

jrodguitar commented Oct 16, 2019

just a minor typo it should be name="com.github.johrstrom"

But yes, after adding the extra logging i can see the below line logged only once in every minion.
2019-10-16 21:04:29,510 DEBUG c.g.j.l.PrometheusServer: Creating Prometheus Server

but that line occurs everytime in the master

@jrodguitar
Copy link

jrodguitar commented Oct 16, 2019

this is the entire log for a minion. I have blurred any ip address, tho

2019-10-16 21:01:25,706 INFO o.a.j.u.JMeterUtils: Setting Locale to en_EN
2019-10-16 21:01:25,719 INFO o.a.j.JMeter: Loading user properties from: /opt/ggs/config/ggs.properties
2019-10-16 21:01:25,719 INFO o.a.j.JMeter: Loading system properties from: /opt/jmeter/bin/system.properties
2019-10-16 21:01:25,720 INFO o.a.j.JMeter: Setting System property: server_port=1099
2019-10-16 21:01:25,720 INFO o.a.j.JMeter: Setting System property: server.rmi.localport=60001
2019-10-16 21:01:25,720 INFO o.a.j.JMeter: Setting System property: server_port=1099
2019-10-16 21:01:25,720 INFO o.a.j.JMeter: Setting JMeter property: server.rmi.ssl.disable=true
2019-10-16 21:01:25,720 INFO o.a.j.JMeter: LogLevel: com.github.johrstrom=DEBUG
2019-10-16 21:01:25,725 INFO o.a.j.JMeter: Copyright (c) 1998-2019 The Apache Software Foundation
2019-10-16 21:01:25,725 INFO o.a.j.JMeter: Version 5.1 r1853635
2019-10-16 21:01:25,725 INFO o.a.j.JMeter: java.version=1.8.0_222
2019-10-16 21:01:25,725 INFO o.a.j.JMeter: java.vm.name=OpenJDK 64-Bit Server VM
2019-10-16 21:01:25,726 INFO o.a.j.JMeter: os.name=Linux
2019-10-16 21:01:25,726 INFO o.a.j.JMeter: os.arch=amd64
2019-10-16 21:01:25,726 INFO o.a.j.JMeter: os.version=4.14.146-119.123.amzn2.x86_64
2019-10-16 21:01:25,726 INFO o.a.j.JMeter: file.encoding=UTF-8
2019-10-16 21:01:25,726 INFO o.a.j.JMeter: java.awt.headless=true
2019-10-16 21:01:25,726 INFO o.a.j.JMeter: Max memory     =1073741824
2019-10-16 21:01:25,726 INFO o.a.j.JMeter: Available Processors =8
2019-10-16 21:01:25,740 INFO o.a.j.JMeter: Default Locale=English (EN)
2019-10-16 21:01:25,741 INFO o.a.j.JMeter: JMeter  Locale=English (EN)
2019-10-16 21:01:25,741 INFO o.a.j.JMeter: JMeterHome=/opt/jmeter
2019-10-16 21:01:25,741 INFO o.a.j.JMeter: user.dir  =/
2019-10-16 21:01:25,741 INFO o.a.j.JMeter: PWD       =/
2019-10-16 21:01:25,741 INFO o.a.j.JMeter: IP: some.ip.address Name:  FullName: 
2019-10-16 21:01:25,748 INFO o.a.j.r.RmiUtils: Disabling SSL for RMI as server.rmi.ssl.disable is set to 'true'
2019-10-16 21:01:25,748 INFO o.a.j.r.RmiUtils: Disabling SSL for RMI as server.rmi.ssl.disable is set to 'true'
2019-10-16 21:01:25,767 INFO o.a.j.e.RemoteJMeterEngineImpl: Starting backing engine on 1099
2019-10-16 21:01:25,767 INFO o.a.j.r.RmiUtils: System property 'java.rmi.server.hostname' is not defined, using localHost address
2019-10-16 21:01:25,767 INFO o.a.j.r.RmiUtils: Local IP address=some.ip.address
2019-10-16 21:01:25,768 INFO o.a.j.e.RemoteJMeterEngineImpl: IP address is a site-local address; this may cause problems with remote access.
	Can be overridden by defining the system property 'java.rmi.server.hostname' - see jmeter-server script file
2019-10-16 21:01:25,768 INFO o.a.j.e.RemoteJMeterEngineImpl: Creating RMI registry (server.rmi.create=true)
2019-10-16 21:01:25,768 INFO o.a.j.r.RmiUtils: Disabling SSL for RMI as server.rmi.ssl.disable is set to 'true'
2019-10-16 21:01:25,768 INFO o.a.j.r.RmiUtils: Disabling SSL for RMI as server.rmi.ssl.disable is set to 'true'
2019-10-16 21:01:25,770 INFO o.a.j.e.RemoteJMeterEngineImpl: Bound to RMI registry on port 1099
2019-10-16 21:04:29,099 INFO o.a.j.s.SampleEvent: List of sample_variables: []
2019-10-16 21:04:29,104 INFO o.a.j.s.BatchSampleSender: Using batching for this run. Thresholds: num=100, time=60000
2019-10-16 21:04:29,105 INFO o.a.j.s.DataStrippingSampleSender: Using DataStrippingSampleSender for this run with stripAlsoOnError: true
2019-10-16 21:04:29,106 INFO o.a.j.s.BatchSampleSender: Using batching for this run. Thresholds: num=100, time=60000
2019-10-16 21:04:29,106 INFO o.a.j.s.DataStrippingSampleSender: Using DataStrippingSampleSender for this run with stripAlsoOnError: true
2019-10-16 21:04:29,106 INFO o.a.j.s.BatchSampleSender: Using batching for this run. Thresholds: num=100, time=60000
2019-10-16 21:04:29,106 INFO o.a.j.s.DataStrippingSampleSender: Using DataStrippingSampleSender for this run with stripAlsoOnError: true
2019-10-16 21:04:29,138 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/html is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
2019-10-16 21:04:29,138 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for application/xhtml+xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
2019-10-16 21:04:29,138 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for application/xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
2019-10-16 21:04:29,138 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser
2019-10-16 21:04:29,138 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/vnd.wap.wml is org.apache.jmeter.protocol.http.parser.RegexpHTMLParser
2019-10-16 21:04:29,138 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/css is org.apache.jmeter.protocol.http.parser.CssParser
2019-10-16 21:04:29,163 INFO o.a.j.s.BatchSampleSender: Using batching for this run. Thresholds: num=100, time=60000
2019-10-16 21:04:29,163 INFO o.a.j.s.DataStrippingSampleSender: Using DataStrippingSampleSender for this run with stripAlsoOnError: true
2019-10-16 21:04:29,163 INFO o.a.j.s.BatchSampleSender: Using batching for this run. Thresholds: num=100, time=60000
2019-10-16 21:04:29,163 INFO o.a.j.s.DataStrippingSampleSender: Using DataStrippingSampleSender for this run with stripAlsoOnError: true
2019-10-16 21:04:29,173 INFO o.a.j.e.RemoteJMeterEngineImpl: Creating JMeter engine on host some.ip.address base 'opt/ggs'
2019-10-16 21:04:29,174 INFO o.a.j.e.RemoteJMeterEngineImpl: Remote client host: some.client.ip.address
2019-10-16 21:04:29,176 INFO o.a.j.s.FileServer: Default base='/'
2019-10-16 21:04:29,181 INFO o.a.j.s.FileServer: Set new base='opt/ggs'
2019-10-16 21:04:29,182 INFO o.a.j.e.StandardJMeterEngine: Applying properties {}
2019-10-16 21:04:29,182 INFO o.a.j.e.RemoteJMeterEngineImpl: Running test
2019-10-16 21:04:29,185 INFO o.a.j.e.StandardJMeterEngine: Running the test!
2019-10-16 21:04:29,185 INFO o.a.j.s.SampleEvent: List of sample_variables: []
2019-10-16 21:04:29,192 INFO o.a.j.e.u.CompoundVariable: Note: Function class names must contain the string: '.functions.'
2019-10-16 21:04:29,192 INFO o.a.j.e.u.CompoundVariable: Note: Function class names must not contain the string: '.gui.'
2019-10-16 21:04:29,471 INFO k.a.j.t.UltimateThreadGroup: GUI threads profile will be ignored
2019-10-16 21:04:29,492 INFO k.a.j.t.UltimateThreadGroup: Setting threads profile from property threads_schedule: spawn(4,0s,30s,100s,30s)
2019-10-16 21:04:29,493 WARN c.g.j.l.PrometheusListener: Collector registry has not yet been initialized, doing it now
2019-10-16 21:04:29,494 DEBUG c.g.j.c.JMeterCollectorRegistry: Creating prometheus collector registry
2019-10-16 21:04:29,505 DEBUG c.g.j.l.PrometheusListener: Creating collector from configuration: [collector.help: default help string, collector.metric_name: jmeter_samples_latency, collector.type: SUMMARY, collector.labels: [label, code], collector.quantiles_or_buckets: 0.75,0.5|0.95,0.1|0.99,0.01, listener.collector.measuring: Latency, ]
2019-10-16 21:04:29,506 DEBUG c.g.j.c.JMeterCollectorRegistry: created and registered [collector.help: default help string, collector.metric_name: jmeter_samples_latency, collector.type: SUMMARY, collector.labels: [label, code], collector.quantiles_or_buckets: 0.75,0.5|0.95,0.1|0.99,0.01, listener.collector.measuring: Latency, ]
2019-10-16 21:04:29,507 DEBUG c.g.j.l.PrometheusListener: added jmeter_samples_latency to list of collectors
2019-10-16 21:04:29,507 DEBUG c.g.j.l.PrometheusListener: Creating collector from configuration: [collector.help: default help string, collector.metric_name: jmeter_samples_response_time, collector.type: SUMMARY, collector.labels: [label, code], collector.quantiles_or_buckets: 0.75,0.5|0.95,0.1|0.99,0.01, listener.collector.measuring: ResponseTime, ]
2019-10-16 21:04:29,507 DEBUG c.g.j.c.JMeterCollectorRegistry: created and registered [collector.help: default help string, collector.metric_name: jmeter_samples_response_time, collector.type: SUMMARY, collector.labels: [label, code], collector.quantiles_or_buckets: 0.75,0.5|0.95,0.1|0.99,0.01, listener.collector.measuring: ResponseTime, ]
2019-10-16 21:04:29,508 DEBUG c.g.j.l.PrometheusListener: added jmeter_samples_response_time to list of collectors
2019-10-16 21:04:29,508 DEBUG c.g.j.l.PrometheusListener: Creating collector from configuration: [collector.help: default help string, collector.metric_name: jmeter_samples_success_ratio, collector.type: SUCCESS_RATIO, collector.labels: [], collector.quantiles_or_buckets: , listener.collector.measuring: SuccessRatio, ]
2019-10-16 21:04:29,508 DEBUG c.g.j.c.JMeterCollectorRegistry: created and registered [collector.help: default help string, collector.metric_name: jmeter_samples_success_ratio, collector.type: SUCCESS_RATIO, collector.labels: [], collector.quantiles_or_buckets: , listener.collector.measuring: SuccessRatio, ]
2019-10-16 21:04:29,509 DEBUG c.g.j.l.PrometheusListener: added jmeter_samples_success_ratio to list of collectors
2019-10-16 21:04:29,509 WARN c.g.j.l.PrometheusListener: Prometheus server has not yet been initialized, doing it now
2019-10-16 21:04:29,510 DEBUG c.g.j.l.PrometheusServer: Creating Prometheus Server
2019-10-16 21:04:29,554 INFO o.a.j.e.StandardJMeterEngine: Starting ThreadGroup: 1 : Thread Group
2019-10-16 21:04:29,555 INFO k.a.j.t.UltimateThreadGroup: GUI threads profile will be ignored
2019-10-16 21:04:29,555 INFO k.a.j.t.UltimateThreadGroup: Setting threads profile from property threads_schedule: spawn(4,0s,30s,100s,30s)
2019-10-16 21:04:29,555 INFO o.a.j.e.StandardJMeterEngine: Starting 4 threads for group Thread Group.
2019-10-16 21:04:29,555 INFO o.a.j.e.StandardJMeterEngine: Thread will continue on error
2019-10-16 21:04:29,555 INFO k.a.j.t.UltimateThreadGroup: GUI threads profile will be ignored
2019-10-16 21:04:29,555 INFO k.a.j.t.UltimateThreadGroup: Setting threads profile from property threads_schedule: spawn(4,0s,30s,100s,30s)
2019-10-16 21:04:29,556 INFO k.a.j.t.AbstractSimpleThreadGroup: Starting thread group number 1 threads 4
2019-10-16 21:04:29,562 INFO k.a.j.t.AbstractSimpleThreadGroup: Started thread group number 1
2019-10-16 21:04:29,562 INFO o.a.j.e.StandardJMeterEngine: All thread groups have been started
2019-10-16 21:04:37,056 INFO o.a.j.t.JMeterThread: Thread started: some.ip.address-Thread Group 1-4
2019-10-16 21:04:37,058 INFO o.a.j.s.FileServer: Stored: /opt/ggs/addresses.csv Alias: /opt/ggs/addresses.csv@"All threads"
2019-10-16 21:04:37,081 INFO o.a.j.p.h.s.HTTPHCAbstractImpl: Local host = jmeter-slaves-68d96c868b-dpw6l
2019-10-16 21:04:37,086 INFO o.a.j.p.h.s.HTTPHC4Impl: HTTP request retry count = 0
2019-10-16 21:04:37,088 INFO o.a.j.s.SampleResult: Note: Sample TimeStamps are START times
2019-10-16 21:04:37,088 INFO o.a.j.s.SampleResult: sampleresult.default.encoding is set to ISO-8859-1
2019-10-16 21:04:37,088 INFO o.a.j.s.SampleResult: sampleresult.useNanoTime=true
2019-10-16 21:04:37,088 INFO o.a.j.s.SampleResult: sampleresult.nanoThreadSleep=5000
2019-10-16 21:04:44,557 INFO o.a.j.t.JMeterThread: Thread started: some.ip.address-Thread Group 1-3
2019-10-16 21:04:46,476 INFO o.a.j.u.JsseSSLManager: Using default SSL protocol: TLS
2019-10-16 21:04:46,476 INFO o.a.j.u.JsseSSLManager: SSL session context: per-thread
2019-10-16 21:04:52,056 INFO o.a.j.t.JMeterThread: Thread started: some.ip.address-Thread Group 1-2
2019-10-16 21:04:59,556 INFO o.a.j.t.JMeterThread: Thread started: some.ip.address-Thread Group 1-1
2019-10-16 21:06:47,905 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: some.ip.address-Thread Group 1-4
2019-10-16 21:06:47,905 INFO o.a.j.t.JMeterThread: Thread finished: some.ip.address-Thread Group 1-4
2019-10-16 21:06:55,335 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: some.ip.address-Thread Group 1-3
2019-10-16 21:06:55,335 INFO o.a.j.t.JMeterThread: Thread finished: some.ip.address-Thread Group 1-3
2019-10-16 21:07:02,086 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: some.ip.address-Thread Group 1-2
2019-10-16 21:07:02,086 INFO o.a.j.t.JMeterThread: Thread finished: some.ip.address-Thread Group 1-2
2019-10-16 21:07:09,591 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: some.ip.address-Thread Group 1-1
2019-10-16 21:07:09,591 INFO o.a.j.t.JMeterThread: Thread finished: some.ip.address-Thread Group 1-1
2019-10-16 21:07:09,592 INFO o.a.j.e.StandardJMeterEngine: Notifying test listeners of end of test
2019-10-16 21:07:09,592 INFO o.a.j.s.FileServer: Close: /opt/ggs/addresses.csv@"All threads"
2019-10-16 21:07:09,592 INFO o.a.j.s.DataStrippingSampleSender: Test Ended on some.ip.address
2019-10-16 21:07:09,592 INFO o.a.j.s.BatchSampleSender: Test Ended on some.ip.address
2019-10-16 21:07:09,594 INFO o.a.j.s.DataStrippingSampleSender: Test Ended on some.ip.address
2019-10-16 21:07:09,594 INFO o.a.j.s.BatchSampleSender: Test Ended on some.ip.address
2019-10-16 21:07:09,595 INFO o.a.j.s.DataStrippingSampleSender: Test Ended on some.ip.address
2019-10-16 21:07:09,595 INFO o.a.j.s.BatchSampleSender: Test Ended on some.ip.address
2019-10-16 21:07:09,596 INFO o.a.j.s.DataStrippingSampleSender: Test Ended on some.ip.address
2019-10-16 21:07:09,596 INFO o.a.j.s.BatchSampleSender: Test Ended on some.ip.address
2019-10-16 21:07:09,597 DEBUG c.g.j.c.JMeterCollectorRegistry: unregistering jmeter_samples_latency
2019-10-16 21:07:09,597 DEBUG c.g.j.c.JMeterCollectorRegistry: unregistering jmeter_samples_success_ratio
2019-10-16 21:07:09,598 DEBUG c.g.j.c.JMeterCollectorRegistry: unregistering jmeter_samples_response_time
2019-10-16 21:07:09,598 INFO o.a.j.s.DataStrippingSampleSender: Test Ended on some.ip.address
2019-10-16 21:07:09,598 INFO o.a.j.s.BatchSampleSender: Test Ended on some.ip.address
2019-10-16 21:07:09,601 INFO o.a.j.e.StandardJMeterEngine: Test has ended on host some.ip.address 

@jrodguitar
Copy link

jrodguitar commented Oct 17, 2019

So after a little digging, and git cloning your repo, i noticed that the problem is due to shutting down the service executor.

you can reproduce the error, in your unit test. if you update the test to this

public class PrometheusServerTest {
	
	@Test
	public void ensureCleanStartStop() throws Exception {
		PrometheusServer server = PrometheusServer.getInstance();
		Assert.assertNotNull(server);
		
		server.start();
		Thread.currentThread();
		Thread.sleep(1000);
		String data = getScrapes();
		server.stop();
		
		server.start();
		Thread.currentThread();
		Thread.sleep(1000);
		String data2 = getScrapes();
		server.stop();
	}

	private String getScrapes() throws IOException {
		URL url = new URL("http://localhost:9270/metrics");
		URLConnection conn = url.openConnection();
		conn.setReadTimeout(3000);
		BufferedReader in = new BufferedReader(new InputStreamReader(conn.getInputStream()));

		StringBuilder sb = new StringBuilder();
		String line = "";

		while ((line = in.readLine()) != null) {
			sb.append(line);
		}
		return sb.toString();
	}
}

so for the test to pass you have 2 options:
uncomment the serviceExecutor.shutdown() method. Just to see behaviour 😄 unrealistic of course.
or create a service executor everytime the server is created.

@johrstrom johrstrom self-assigned this Oct 18, 2019
@johrstrom
Copy link
Owner Author

Thanks for all the info. I started to look into this, then got into a rabbit hole trying to containerize my jmeter setup. I'll try to get around to this this weekend.

@joris-lambrechts
Copy link

For what's worth, you can get the same behaviour when you load your example in JMeter and start / stop the test. The first time the server starts correctly and Prometheus can scrape it. Consecutive times the server returns an empty response.

@johrstrom
Copy link
Owner Author

Thanks all for contributing to this. GH closed this based off of my commit message, but I've released version 0.5.2 which I believe resolves this. I'll keep this open for just a little bit to get some confirmation.

Let me know if it doesn't fix it (or even if it does let me know). Thanks again!

@johrstrom johrstrom reopened this Nov 5, 2019
@joris-lambrechts
Copy link

Works fine in JMeter GUI mode 😄 Thanks for the quick fix, helps during test case development!

@johrstrom
Copy link
Owner Author

I'm going to close this now. Let me know if it comes back! thanks again all.

@beemi
Copy link

beemi commented Aug 27, 2020

Able to replicate against 0.6.0 version

@beemi
Copy link

beemi commented Aug 27, 2020

this is the entire log for a minion. I have blurred any ip address, tho

2019-10-16 21:01:25,706 INFO o.a.j.u.JMeterUtils: Setting Locale to en_EN

2019-10-16 21:01:25,719 INFO o.a.j.JMeter: Loading user properties from: /opt/ggs/config/ggs.properties

2019-10-16 21:01:25,719 INFO o.a.j.JMeter: Loading system properties from: /opt/jmeter/bin/system.properties

2019-10-16 21:01:25,720 INFO o.a.j.JMeter: Setting System property: server_port=1099

2019-10-16 21:01:25,720 INFO o.a.j.JMeter: Setting System property: server.rmi.localport=60001

2019-10-16 21:01:25,720 INFO o.a.j.JMeter: Setting System property: server_port=1099

2019-10-16 21:01:25,720 INFO o.a.j.JMeter: Setting JMeter property: server.rmi.ssl.disable=true

2019-10-16 21:01:25,720 INFO o.a.j.JMeter: LogLevel: com.github.johrstrom=DEBUG

2019-10-16 21:01:25,725 INFO o.a.j.JMeter: Copyright (c) 1998-2019 The Apache Software Foundation

2019-10-16 21:01:25,725 INFO o.a.j.JMeter: Version 5.1 r1853635

2019-10-16 21:01:25,725 INFO o.a.j.JMeter: java.version=1.8.0_222

2019-10-16 21:01:25,725 INFO o.a.j.JMeter: java.vm.name=OpenJDK 64-Bit Server VM

2019-10-16 21:01:25,726 INFO o.a.j.JMeter: os.name=Linux

2019-10-16 21:01:25,726 INFO o.a.j.JMeter: os.arch=amd64

2019-10-16 21:01:25,726 INFO o.a.j.JMeter: os.version=4.14.146-119.123.amzn2.x86_64

2019-10-16 21:01:25,726 INFO o.a.j.JMeter: file.encoding=UTF-8

2019-10-16 21:01:25,726 INFO o.a.j.JMeter: java.awt.headless=true

2019-10-16 21:01:25,726 INFO o.a.j.JMeter: Max memory     =1073741824

2019-10-16 21:01:25,726 INFO o.a.j.JMeter: Available Processors =8

2019-10-16 21:01:25,740 INFO o.a.j.JMeter: Default Locale=English (EN)

2019-10-16 21:01:25,741 INFO o.a.j.JMeter: JMeter  Locale=English (EN)

2019-10-16 21:01:25,741 INFO o.a.j.JMeter: JMeterHome=/opt/jmeter

2019-10-16 21:01:25,741 INFO o.a.j.JMeter: user.dir  =/

2019-10-16 21:01:25,741 INFO o.a.j.JMeter: PWD       =/

2019-10-16 21:01:25,741 INFO o.a.j.JMeter: IP: some.ip.address Name:  FullName: 

2019-10-16 21:01:25,748 INFO o.a.j.r.RmiUtils: Disabling SSL for RMI as server.rmi.ssl.disable is set to 'true'

2019-10-16 21:01:25,748 INFO o.a.j.r.RmiUtils: Disabling SSL for RMI as server.rmi.ssl.disable is set to 'true'

2019-10-16 21:01:25,767 INFO o.a.j.e.RemoteJMeterEngineImpl: Starting backing engine on 1099

2019-10-16 21:01:25,767 INFO o.a.j.r.RmiUtils: System property 'java.rmi.server.hostname' is not defined, using localHost address

2019-10-16 21:01:25,767 INFO o.a.j.r.RmiUtils: Local IP address=some.ip.address

2019-10-16 21:01:25,768 INFO o.a.j.e.RemoteJMeterEngineImpl: IP address is a site-local address; this may cause problems with remote access.

	Can be overridden by defining the system property 'java.rmi.server.hostname' - see jmeter-server script file

2019-10-16 21:01:25,768 INFO o.a.j.e.RemoteJMeterEngineImpl: Creating RMI registry (server.rmi.create=true)

2019-10-16 21:01:25,768 INFO o.a.j.r.RmiUtils: Disabling SSL for RMI as server.rmi.ssl.disable is set to 'true'

2019-10-16 21:01:25,768 INFO o.a.j.r.RmiUtils: Disabling SSL for RMI as server.rmi.ssl.disable is set to 'true'

2019-10-16 21:01:25,770 INFO o.a.j.e.RemoteJMeterEngineImpl: Bound to RMI registry on port 1099

2019-10-16 21:04:29,099 INFO o.a.j.s.SampleEvent: List of sample_variables: []

2019-10-16 21:04:29,104 INFO o.a.j.s.BatchSampleSender: Using batching for this run. Thresholds: num=100, time=60000

2019-10-16 21:04:29,105 INFO o.a.j.s.DataStrippingSampleSender: Using DataStrippingSampleSender for this run with stripAlsoOnError: true

2019-10-16 21:04:29,106 INFO o.a.j.s.BatchSampleSender: Using batching for this run. Thresholds: num=100, time=60000

2019-10-16 21:04:29,106 INFO o.a.j.s.DataStrippingSampleSender: Using DataStrippingSampleSender for this run with stripAlsoOnError: true

2019-10-16 21:04:29,106 INFO o.a.j.s.BatchSampleSender: Using batching for this run. Thresholds: num=100, time=60000

2019-10-16 21:04:29,106 INFO o.a.j.s.DataStrippingSampleSender: Using DataStrippingSampleSender for this run with stripAlsoOnError: true

2019-10-16 21:04:29,138 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/html is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser

2019-10-16 21:04:29,138 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for application/xhtml+xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser

2019-10-16 21:04:29,138 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for application/xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser

2019-10-16 21:04:29,138 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/xml is org.apache.jmeter.protocol.http.parser.LagartoBasedHtmlParser

2019-10-16 21:04:29,138 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/vnd.wap.wml is org.apache.jmeter.protocol.http.parser.RegexpHTMLParser

2019-10-16 21:04:29,138 INFO o.a.j.p.h.s.HTTPSamplerBase: Parser for text/css is org.apache.jmeter.protocol.http.parser.CssParser

2019-10-16 21:04:29,163 INFO o.a.j.s.BatchSampleSender: Using batching for this run. Thresholds: num=100, time=60000

2019-10-16 21:04:29,163 INFO o.a.j.s.DataStrippingSampleSender: Using DataStrippingSampleSender for this run with stripAlsoOnError: true

2019-10-16 21:04:29,163 INFO o.a.j.s.BatchSampleSender: Using batching for this run. Thresholds: num=100, time=60000

2019-10-16 21:04:29,163 INFO o.a.j.s.DataStrippingSampleSender: Using DataStrippingSampleSender for this run with stripAlsoOnError: true

2019-10-16 21:04:29,173 INFO o.a.j.e.RemoteJMeterEngineImpl: Creating JMeter engine on host some.ip.address base 'opt/ggs'

2019-10-16 21:04:29,174 INFO o.a.j.e.RemoteJMeterEngineImpl: Remote client host: some.client.ip.address

2019-10-16 21:04:29,176 INFO o.a.j.s.FileServer: Default base='/'

2019-10-16 21:04:29,181 INFO o.a.j.s.FileServer: Set new base='opt/ggs'

2019-10-16 21:04:29,182 INFO o.a.j.e.StandardJMeterEngine: Applying properties {}

2019-10-16 21:04:29,182 INFO o.a.j.e.RemoteJMeterEngineImpl: Running test

2019-10-16 21:04:29,185 INFO o.a.j.e.StandardJMeterEngine: Running the test!

2019-10-16 21:04:29,185 INFO o.a.j.s.SampleEvent: List of sample_variables: []

2019-10-16 21:04:29,192 INFO o.a.j.e.u.CompoundVariable: Note: Function class names must contain the string: '.functions.'

2019-10-16 21:04:29,192 INFO o.a.j.e.u.CompoundVariable: Note: Function class names must not contain the string: '.gui.'

2019-10-16 21:04:29,471 INFO k.a.j.t.UltimateThreadGroup: GUI threads profile will be ignored

2019-10-16 21:04:29,492 INFO k.a.j.t.UltimateThreadGroup: Setting threads profile from property threads_schedule: spawn(4,0s,30s,100s,30s)

2019-10-16 21:04:29,493 WARN c.g.j.l.PrometheusListener: Collector registry has not yet been initialized, doing it now

2019-10-16 21:04:29,494 DEBUG c.g.j.c.JMeterCollectorRegistry: Creating prometheus collector registry

2019-10-16 21:04:29,505 DEBUG c.g.j.l.PrometheusListener: Creating collector from configuration: [collector.help: default help string, collector.metric_name: jmeter_samples_latency, collector.type: SUMMARY, collector.labels: [label, code], collector.quantiles_or_buckets: 0.75,0.5|0.95,0.1|0.99,0.01, listener.collector.measuring: Latency, ]

2019-10-16 21:04:29,506 DEBUG c.g.j.c.JMeterCollectorRegistry: created and registered [collector.help: default help string, collector.metric_name: jmeter_samples_latency, collector.type: SUMMARY, collector.labels: [label, code], collector.quantiles_or_buckets: 0.75,0.5|0.95,0.1|0.99,0.01, listener.collector.measuring: Latency, ]

2019-10-16 21:04:29,507 DEBUG c.g.j.l.PrometheusListener: added jmeter_samples_latency to list of collectors

2019-10-16 21:04:29,507 DEBUG c.g.j.l.PrometheusListener: Creating collector from configuration: [collector.help: default help string, collector.metric_name: jmeter_samples_response_time, collector.type: SUMMARY, collector.labels: [label, code], collector.quantiles_or_buckets: 0.75,0.5|0.95,0.1|0.99,0.01, listener.collector.measuring: ResponseTime, ]

2019-10-16 21:04:29,507 DEBUG c.g.j.c.JMeterCollectorRegistry: created and registered [collector.help: default help string, collector.metric_name: jmeter_samples_response_time, collector.type: SUMMARY, collector.labels: [label, code], collector.quantiles_or_buckets: 0.75,0.5|0.95,0.1|0.99,0.01, listener.collector.measuring: ResponseTime, ]

2019-10-16 21:04:29,508 DEBUG c.g.j.l.PrometheusListener: added jmeter_samples_response_time to list of collectors

2019-10-16 21:04:29,508 DEBUG c.g.j.l.PrometheusListener: Creating collector from configuration: [collector.help: default help string, collector.metric_name: jmeter_samples_success_ratio, collector.type: SUCCESS_RATIO, collector.labels: [], collector.quantiles_or_buckets: , listener.collector.measuring: SuccessRatio, ]

2019-10-16 21:04:29,508 DEBUG c.g.j.c.JMeterCollectorRegistry: created and registered [collector.help: default help string, collector.metric_name: jmeter_samples_success_ratio, collector.type: SUCCESS_RATIO, collector.labels: [], collector.quantiles_or_buckets: , listener.collector.measuring: SuccessRatio, ]

2019-10-16 21:04:29,509 DEBUG c.g.j.l.PrometheusListener: added jmeter_samples_success_ratio to list of collectors

2019-10-16 21:04:29,509 WARN c.g.j.l.PrometheusListener: Prometheus server has not yet been initialized, doing it now

2019-10-16 21:04:29,510 DEBUG c.g.j.l.PrometheusServer: Creating Prometheus Server

2019-10-16 21:04:29,554 INFO o.a.j.e.StandardJMeterEngine: Starting ThreadGroup: 1 : Thread Group

2019-10-16 21:04:29,555 INFO k.a.j.t.UltimateThreadGroup: GUI threads profile will be ignored

2019-10-16 21:04:29,555 INFO k.a.j.t.UltimateThreadGroup: Setting threads profile from property threads_schedule: spawn(4,0s,30s,100s,30s)

2019-10-16 21:04:29,555 INFO o.a.j.e.StandardJMeterEngine: Starting 4 threads for group Thread Group.

2019-10-16 21:04:29,555 INFO o.a.j.e.StandardJMeterEngine: Thread will continue on error

2019-10-16 21:04:29,555 INFO k.a.j.t.UltimateThreadGroup: GUI threads profile will be ignored

2019-10-16 21:04:29,555 INFO k.a.j.t.UltimateThreadGroup: Setting threads profile from property threads_schedule: spawn(4,0s,30s,100s,30s)

2019-10-16 21:04:29,556 INFO k.a.j.t.AbstractSimpleThreadGroup: Starting thread group number 1 threads 4

2019-10-16 21:04:29,562 INFO k.a.j.t.AbstractSimpleThreadGroup: Started thread group number 1

2019-10-16 21:04:29,562 INFO o.a.j.e.StandardJMeterEngine: All thread groups have been started

2019-10-16 21:04:37,056 INFO o.a.j.t.JMeterThread: Thread started: some.ip.address-Thread Group 1-4

2019-10-16 21:04:37,058 INFO o.a.j.s.FileServer: Stored: /opt/ggs/addresses.csv Alias: /opt/ggs/addresses.csv@"All threads"

2019-10-16 21:04:37,081 INFO o.a.j.p.h.s.HTTPHCAbstractImpl: Local host = jmeter-slaves-68d96c868b-dpw6l

2019-10-16 21:04:37,086 INFO o.a.j.p.h.s.HTTPHC4Impl: HTTP request retry count = 0

2019-10-16 21:04:37,088 INFO o.a.j.s.SampleResult: Note: Sample TimeStamps are START times

2019-10-16 21:04:37,088 INFO o.a.j.s.SampleResult: sampleresult.default.encoding is set to ISO-8859-1

2019-10-16 21:04:37,088 INFO o.a.j.s.SampleResult: sampleresult.useNanoTime=true

2019-10-16 21:04:37,088 INFO o.a.j.s.SampleResult: sampleresult.nanoThreadSleep=5000

2019-10-16 21:04:44,557 INFO o.a.j.t.JMeterThread: Thread started: some.ip.address-Thread Group 1-3

2019-10-16 21:04:46,476 INFO o.a.j.u.JsseSSLManager: Using default SSL protocol: TLS

2019-10-16 21:04:46,476 INFO o.a.j.u.JsseSSLManager: SSL session context: per-thread

2019-10-16 21:04:52,056 INFO o.a.j.t.JMeterThread: Thread started: some.ip.address-Thread Group 1-2

2019-10-16 21:04:59,556 INFO o.a.j.t.JMeterThread: Thread started: some.ip.address-Thread Group 1-1

2019-10-16 21:06:47,905 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: some.ip.address-Thread Group 1-4

2019-10-16 21:06:47,905 INFO o.a.j.t.JMeterThread: Thread finished: some.ip.address-Thread Group 1-4

2019-10-16 21:06:55,335 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: some.ip.address-Thread Group 1-3

2019-10-16 21:06:55,335 INFO o.a.j.t.JMeterThread: Thread finished: some.ip.address-Thread Group 1-3

2019-10-16 21:07:02,086 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: some.ip.address-Thread Group 1-2

2019-10-16 21:07:02,086 INFO o.a.j.t.JMeterThread: Thread finished: some.ip.address-Thread Group 1-2

2019-10-16 21:07:09,591 INFO o.a.j.t.JMeterThread: Stopping because end time detected by thread: some.ip.address-Thread Group 1-1

2019-10-16 21:07:09,591 INFO o.a.j.t.JMeterThread: Thread finished: some.ip.address-Thread Group 1-1

2019-10-16 21:07:09,592 INFO o.a.j.e.StandardJMeterEngine: Notifying test listeners of end of test

2019-10-16 21:07:09,592 INFO o.a.j.s.FileServer: Close: /opt/ggs/addresses.csv@"All threads"

2019-10-16 21:07:09,592 INFO o.a.j.s.DataStrippingSampleSender: Test Ended on some.ip.address

2019-10-16 21:07:09,592 INFO o.a.j.s.BatchSampleSender: Test Ended on some.ip.address

2019-10-16 21:07:09,594 INFO o.a.j.s.DataStrippingSampleSender: Test Ended on some.ip.address

2019-10-16 21:07:09,594 INFO o.a.j.s.BatchSampleSender: Test Ended on some.ip.address

2019-10-16 21:07:09,595 INFO o.a.j.s.DataStrippingSampleSender: Test Ended on some.ip.address

2019-10-16 21:07:09,595 INFO o.a.j.s.BatchSampleSender: Test Ended on some.ip.address

2019-10-16 21:07:09,596 INFO o.a.j.s.DataStrippingSampleSender: Test Ended on some.ip.address

2019-10-16 21:07:09,596 INFO o.a.j.s.BatchSampleSender: Test Ended on some.ip.address

2019-10-16 21:07:09,597 DEBUG c.g.j.c.JMeterCollectorRegistry: unregistering jmeter_samples_latency

2019-10-16 21:07:09,597 DEBUG c.g.j.c.JMeterCollectorRegistry: unregistering jmeter_samples_success_ratio

2019-10-16 21:07:09,598 DEBUG c.g.j.c.JMeterCollectorRegistry: unregistering jmeter_samples_response_time

2019-10-16 21:07:09,598 INFO o.a.j.s.DataStrippingSampleSender: Test Ended on some.ip.address

2019-10-16 21:07:09,598 INFO o.a.j.s.BatchSampleSender: Test Ended on some.ip.address

2019-10-16 21:07:09,601 INFO o.a.j.e.StandardJMeterEngine: Test has ended on host some.ip.address 

Hi, I got same issue by using 0.6.0 version jar.

Running distributed mode using docker, got master and N slaves running on same server, local host:9270 is not reachable.

Did you manage to get the solution for this?

Please advice me

Thanks

@beemi
Copy link

beemi commented Sep 2, 2020

@joris-lambrechts i am seeing same issue for distribution testing.

can you help me on this, master and slaves are running as docker containers.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

4 participants