distributed test not ending - 'Overtime' and 'Waiting for finish...'

[Paul Spehar]

I am using Taurus with JMeter executer distributed.   I have one scenario running locally on the same server where I launch taurus.  The second scenario I have in the distributed section.  On the slave server, i have this property and it appears to be working:

server.exitaftertest=true

After an otherwise successful test run, the jmeter-server exits as expected

~/.bzt/jmeter-taurus/bin/jmeter-server

Writing log file to: /home/ubuntu/jmeter-server.log

Created remote object: UnicastServerRef [liveRef: [endpoint:[10.112.96.180:37970](local),objID:[-65b4a06f:15b6484e2e9:-7fff, -3812683565293000344]]]

Starting the test on host 10.112.96.180 @ Wed Apr 12 23:34:54 UTC 2017 (1492040094449)

Finished the test on host 10.112.96.180 @ Wed Apr 12 23:45:13 UTC 2017 (1492040713085) - exit requested.

However, over on the TAURUS interface, things seem hung up at 100%

The scenario that was running distributed is showing Overtime.

Turus is saying:

00:25:13 INFO: Waiting for finish...

[Andrey Pokhilko]

Hi,

Can you look into process list to see if all JMeter processes have exited? This can only happen if JMeter process is still running.

Andrey Pohilko Chief Scientist P: +7 (909) 631-21-69

--
You received this message because you are subscribed to the Google Groups "codename-taurus" group.
To unsubscribe from this group and stop receiving emails from it, send an email to codename-taur...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/codename-taurus/29c6bd69-29a2-46b7-8e27-ef5398a4fc5d%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Paul Spehar]

I found something interesting while looking into the running processes as you suggested.  jmeter is still running... on the first server.  It must be a misconfiguration of my yml file.  

I was trying to achieve the following:

Server 1 (x.x.x.165):

-taurus is started here

-one of my two scenarios runs here

Server 2 (x.x.x.180):

-running jmeter-server

-the second of my two scenarios runs here

Here is what I just discovered:

Server 1:

-taurus is started here

-one of my two scenarios runs here

           -the second of my two scenarios runs here <-- not what I was hoping for

Server 2:

-running jmeter-server

-the second of my two scenarios ALSO runs here  

This is my yml

---

modules:

  jmeter:

    memory-xmx: 4G

execution:

- distributed:

  - x.x.x.180

  concurrency: 5000

  throughput: 500

  ramp-up: 5m

  hold-for: 5m

  scenario: variant

- concurrency: 100

  throughput: 10

  ramp-up: 5m

  hold-for: 5m

  scenario: master

scenarios:

  variant:

    script: /tmp/my-test/tests/jmx/xxx_Variant.jmx

    variables:

      xxx: /tmp/my-test/tests/csv/xxx.csv

      xxxHOSTS: /tmp/my-test/tests/csv/xxxHosts-xxx.csv

      LOADGENIP: /tmp/my-test/tests/csv/loadGenIp.csv

  master:

    script: /tmp/my-test/tests/jmx/xxx_Master.jmx

    variables:

      xxx: /tmp/my-test/tests/csv/xxx-psi-master.csv

      xxxHOSTS: /tmp/my-test/tests/csv/xxxHosts-xxx.csv

      LOADGENIP: /tmp/my-test/tests/csv/loadGenIp.csv

[Paul Spehar]

I made some yml changes today.  

The two scripts appear to be distributed properly now.  However, the test still hangs at the end with the overtime...

execution:
- concurrency: 1000
  throughput: 100
  ramp-up: 2m
  hold-for: 2m
  scenario:
   script: /tmp/my-test/tests/jmx/xxx_VariantNew.jmx
  variables:
   xxx: /tmp/my-test/tests/csv/xxx-psi.csv
   xxxHOSTS: /tmp/my-test/tests/csv/xxxHosts-xxx.csv
   LOADGENIP: /tmp/my-test/tests/csv/loadGenIp.csv
  distributed:
  - x.x.x.180

- concurrency: 100
  throughput: 10

  ramp-up: 2m
  hold-for: 2m
  scenario:

   script: /tmp/my-test/tests/jmx/xxx_Master.jmx
  variables:
   xxx: /tmp/my-test/tests/csv/xxx-psi-master.csv
   xxxHOSTS: /tmp/my-test/tests/csv/xxxHosts-xxx.csv
   LOADGENIP: /tmp/my-test/tests/csv/loadGenIp.

csv
  distributed:
  - x.x.x.165

processes look like this on the .168 where TAURUS was launched:

 ps aux | grep java

ubuntu   15216  0.0  0.0   4508  1688 pts/0    S    Apr13   0:00 /bin/sh /home/ubuntu/.bzt/jmeter-taurus/bin/jmeter -Djava.rmi.server.hostname=x.x.x.165 -Dserver_port=1099 -s -j jmeter-server.log
ubuntu  

ubuntu   15250  2.7  1.5 9931768 244772 pts/0  Sl   Apr13   0:21 java -server -XX:+HeapDumpOnOutOfMemoryError -Xms4g -Xmx4g -XX:NewSize=128m -XX:MaxNewSize=128m -XX:MaxTenuringThreshold=2 -XX:+CMSClassUnloadingEnabled -d64 -XX:+UseConcMarkSweepGC -XX:+DisableExplicitGC -jar /home/ubuntu/.bzt/jmeter-taurus/bin/ApacheJMeter.jar -Djava.rmi.server.hostname=x.x.x.165 -Dserver_port=1099 -s -j jmeter-server.log
ubuntu  

ubuntu   15502  3.8  1.1 8803152 174716 pts/1  Sl   Apr13   0:29 java -jar /home/ubuntu/.bzt/jmeter-taurus/bin/ApacheJMeter.jar -n -t /tmp/my-test/tests/jmx/modified_xxx_VariantNew-2.jmx -j /tmp/my-test/2017-04-13_23-50-32.402164/jmeter.log -q /tmp/my-test/2017-04-13_23-50-32.402164/jmeter-bzt.properties -G /tmp/my-test/2017-04-13_23-50-32.402164/jmeter-bzt.properties -R10.112.96.180

ubuntu   15520  1.1  1.3 7871256 212868 pts/1  Sl   Apr13   0:08 java -jar /home/ubuntu/.bzt/jmeter-taurus/bin/ApacheJMeter.jar -n -t /tmp/my-test/tests/jmx/modified_xxx_Master.jmx -j /tmp/my-test/2017-04-13_23-50-32.402164/jmeter-1.log -q /tmp/my-test/2017-04-13_23-50-32.402164/jmeter-bzt-1.properties -G /tmp/my-test/2017-04-13_23-50-32.402164/jmeter-bzt-1.properties -R10.112.96.165

And the jmeter logs for both scripts look like this while it is hung:

...

2017/04/13 23:50:34 INFO  - jmeter.engine.DistributedRunner: Remote engines have been started

2017/04/13 23:50:34 INFO  - jmeter.visualizers.backend.BackendListener: Backend Listener - Graphite Shipper:Starting worker with class:class org.apache.jmeter.visualizers.backend.graphite.GraphiteBackendListenerClient and queue capacity:5000

2017/04/13 23:50:34 INFO  - jmeter.visualizers.backend.BackendListener: Backend Listener - Graphite Shipper: Started  worker with class:class org.apache.jmeter.visualizers.backend.graphite.GraphiteBackendListenerClient

2017/04/13 23:50:34 INFO  - jmeter.visualizers.backend.graphite.TextGraphiteMetricsSender: Created TextGraphiteMetricsSender with host:x.x.x.212, port:2003, prefix:jmeter.xxx.

2017/04/13 23:50:34 INFO  - jmeter.JMeter: Started remote host:  x.x.x.180 (1492127434209)

2017/04/13 23:54:49 INFO  - jmeter.JMeter: Finished remote host: x.x.x.180 (1492127689309)

2017/04/13 23:54:54 INFO  - jmeter.JMeter: Interrupting RMI Reaper

the jmeter-server's show a finished end:

Finished the test on host x.x.x.180 @ Thu Apr 13 23:54:49 UTC 2017 (1492127689309)

[Andrey Pokhilko]

Can you make thread dump on hung JMeter process? It might shed some light on what is causing this.

Andrey Pohilko Chief Scientist P: +7 (909) 631-21-69

--
You received this message because you are subscribed to the Google Groups "codename-taurus" group.
To unsubscribe from this group and stop receiving emails from it, send an email to codename-taur...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/codename-taurus/2bdf7f27-8256-42c5-b6db-b93d15e8b5b6%40googlegroups.com.

[pspeharth...@gmail.com]

Here are the thread dumps from the two processes.  Note that the same jmx scripts do not hang in this manner when run in non-distributed fashion.

https://pastebin.com/URGxkUdm

https://pastebin.com/QjUj5VYD

ubuntu   19468  4.4  1.2 8929060 188800 pts/1  Sl   15:03   0:36 java -jar /home/ubuntu/.bzt/jmeter-taurus/bin/ApacheJMeter.jar -n -t /tmp/my-test/tests/jmx/modified_xxx_VariantNew-2.jmx -j /tmp/my-test/2017-04-14_15-03-35.632576/jmeter.log -q /tmp/my-test/2017-04-14_15-03-35.632576/jmeter-bzt.properties -G /tmp/my-test/2017-04-14_15-03-35.632576/jmeter-bzt.properties -Rx.x.x.180
ubuntu   19487  1.1  1.4 7864036 222564 pts/1  Sl   15:03   0:09 java -jar /home/ubuntu/.bzt/jmeter-taurus/bin/ApacheJMeter.jar -n -t /tmp/my-test/tests/jmx/modified_xxx_Master.jmx -j /tmp/my-test/2017-04-14_15-03-35.632576/jmeter-1.log -q /tmp/my-test/2017-04-14_15-03-35.632576/jmeter-bzt-1.properties -G /tmp/my-test/2017-04-14_15-03-35.632576/jmeter-bzt-1.properties -Rx.x.x.165

[Andrey Pokhilko]

One more question - does it happen if you will take JMeter and run this distributed test without Taurus, but using same JMeter with same settings on same machine?

Andrey Pohilko Chief Scientist P: +7 (909) 631-21-69

To view this discussion on the web visit https://groups.google.com/d/msgid/codename-taurus/923528a6-dbc0-45e1-844a-78af227081f4%40googlegroups.com.

[Andrey Pokhilko]

I see BackendListener thread not finished among threads. Are you using BackendListener in your JMX? If yes, can you try disabling it and running again, to see if it is the reason of hanging threads?

Andrey Pohilko Chief Scientist P: +7 (909) 631-21-69

To view this discussion on the web visit https://groups.google.com/d/msgid/codename-taurus/923528a6-dbc0-45e1-844a-78af227081f4%40googlegroups.com.

[pspeharth...@gmail.com]

That was it.  Disabled BackendListener in my two scripts and the test exited as needed.  Thanks!  Interesting thing is that i don't need the grafana live data as much now that I can see how things are running with TAURUS.

I will investigate what might be the issue with BackendListener.  My JMeter scripts have been modified over the past month for usage with TAURUS.  I need to take some time to get them back into a state where they can run using my older bash wrapper script that I was using without TAURUS. I will report back later.