Performance of "Finishing,..." a parallel test run

classic Classic list List threaded Threaded
14 messages Options
Reply | Threaded
Open this post in threaded view
|

Performance of "Finishing,..." a parallel test run

Jeff-351
Running Maven + Java 8 + TestNG 
I have a DataProvider test that runs 20 threads and processes 11,000 data-driven test instances.

Each iteration does the following:
  • Calls a web service
  • inserts a message on a rabbitmq queue
  • caches the request information for later checking
After all 11,000 were submitted, another method loops through the cached requests and verifies they were all processed and inserted into MongoDB.

The total time it takes the test to run through all 11,000 iterations + validation is about 1 min 32 sec.  
Once complete however, the finalization takes another 18 MINUTES!  

Has anyone seen similarly slow performance when finalizing a test run?  I want to ramp this test up by a factor of 10 or more, but I don't think it would ever finish....

--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.
Reply | Threaded
Open this post in threaded view
|

Re: Performance of "Finishing,..." a parallel test run

Cédric Beust ♔-2
Can you clarify what you mean by "finalizing"? Can you run a profiler and find out where these 18 minutes are being spent? It should be easy to track down.



-- 
Cédric


On Thu, Sep 17, 2015 at 3:28 PM, Jeff <[hidden email]> wrote:
Running Maven + Java 8 + TestNG 
I have a DataProvider test that runs 20 threads and processes 11,000 data-driven test instances.

Each iteration does the following:
  • Calls a web service
  • inserts a message on a rabbitmq queue
  • caches the request information for later checking
After all 11,000 were submitted, another method loops through the cached requests and verifies they were all processed and inserted into MongoDB.

The total time it takes the test to run through all 11,000 iterations + validation is about 1 min 32 sec.  
Once complete however, the finalization takes another 18 MINUTES!  

Has anyone seen similarly slow performance when finalizing a test run?  I want to ramp this test up by a factor of 10 or more, but I don't think it would ever finish....

--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.
Reply | Threaded
Open this post in threaded view
|

Re: Performance of "Finishing,..." a parallel test run

Jeff-351
At the end of the mvn test run this is what I see:

   ...
Running 109999 iterations ....
Finishing...

and then it hangs (current run approaching 15 minutes) after it printed the "Finishing..." message.  Eventually it does finish.  I'll try attaching some profiler snapshot images.  If that doesn't work, I'll email them to you directly.




On Thu, Sep 17, 2015 at 8:41 PM, Cédric Beust ♔ <[hidden email]> wrote:
Can you clarify what you mean by "finalizing"? Can you run a profiler and find out where these 18 minutes are being spent? It should be easy to track down.



-- 
Cédric


On Thu, Sep 17, 2015 at 3:28 PM, Jeff <[hidden email]> wrote:
Running Maven + Java 8 + TestNG 
I have a DataProvider test that runs 20 threads and processes 11,000 data-driven test instances.

Each iteration does the following:
  • Calls a web service
  • inserts a message on a rabbitmq queue
  • caches the request information for later checking
After all 11,000 were submitted, another method loops through the cached requests and verifies they were all processed and inserted into MongoDB.

The total time it takes the test to run through all 11,000 iterations + validation is about 1 min 32 sec.  
Once complete however, the finalization takes another 18 MINUTES!  

Has anyone seen similarly slow performance when finalizing a test run?  I want to ramp this test up by a factor of 10 or more, but I don't think it would ever finish....

--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

ProfileSnapshots.zip (576K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Performance of "Finishing,..." a parallel test run

Jeff-351
I just realized that the "Finishing..." message is coming from my SuiteListener.onFinish() method, and that's all it does (see below), so whatever is happening after this (looks like TestNG Report Generation)

    @Override
    public void onFinish(ISuite suite) {
        System.out.println("Finishing...");
    }

FWIW, it's still running (40 minutes)....

On Fri, Sep 18, 2015 at 9:27 AM, Jeff <[hidden email]> wrote:
At the end of the mvn test run this is what I see:

   ...
Running 109999 iterations ....
Finishing...

and then it hangs (current run approaching 15 minutes) after it printed the "Finishing..." message.  Eventually it does finish.  I'll try attaching some profiler snapshot images.  If that doesn't work, I'll email them to you directly.




On Thu, Sep 17, 2015 at 8:41 PM, Cédric Beust ♔ <[hidden email]> wrote:
Can you clarify what you mean by "finalizing"? Can you run a profiler and find out where these 18 minutes are being spent? It should be easy to track down.



-- 
Cédric


On Thu, Sep 17, 2015 at 3:28 PM, Jeff <[hidden email]> wrote:
Running Maven + Java 8 + TestNG 
I have a DataProvider test that runs 20 threads and processes 11,000 data-driven test instances.

Each iteration does the following:
  • Calls a web service
  • inserts a message on a rabbitmq queue
  • caches the request information for later checking
After all 11,000 were submitted, another method loops through the cached requests and verifies they were all processed and inserted into MongoDB.

The total time it takes the test to run through all 11,000 iterations + validation is about 1 min 32 sec.  
Once complete however, the finalization takes another 18 MINUTES!  

Has anyone seen similarly slow performance when finalizing a test run?  I want to ramp this test up by a factor of 10 or more, but I don't think it would ever finish....

--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.
Reply | Threaded
Open this post in threaded view
|

Re: Performance of "Finishing,..." a parallel test run

Cédric Beust ♔-2
Ah yes, it could very well be the report generation. There have been performance problems there for a while but they only manifest themselves for gigantic test suites, and yours seems to fit the profile.

It will be nice to take a look at the profiler report, although I suspect it will highlight string concatenations as the problem. Just a hunch.


-- 
Cédric


On Fri, Sep 18, 2015 at 8:46 AM, Jeff <[hidden email]> wrote:
I just realized that the "Finishing..." message is coming from my SuiteListener.onFinish() method, and that's all it does (see below), so whatever is happening after this (looks like TestNG Report Generation)

    @Override
    public void onFinish(ISuite suite) {
        System.out.println("Finishing...");
    }

FWIW, it's still running (40 minutes)....

On Fri, Sep 18, 2015 at 9:27 AM, Jeff <[hidden email]> wrote:
At the end of the mvn test run this is what I see:

   ...
Running 109999 iterations ....
Finishing...

and then it hangs (current run approaching 15 minutes) after it printed the "Finishing..." message.  Eventually it does finish.  I'll try attaching some profiler snapshot images.  If that doesn't work, I'll email them to you directly.




On Thu, Sep 17, 2015 at 8:41 PM, Cédric Beust ♔ <[hidden email]> wrote:
Can you clarify what you mean by "finalizing"? Can you run a profiler and find out where these 18 minutes are being spent? It should be easy to track down.



-- 
Cédric


On Thu, Sep 17, 2015 at 3:28 PM, Jeff <[hidden email]> wrote:
Running Maven + Java 8 + TestNG 
I have a DataProvider test that runs 20 threads and processes 11,000 data-driven test instances.

Each iteration does the following:
  • Calls a web service
  • inserts a message on a rabbitmq queue
  • caches the request information for later checking
After all 11,000 were submitted, another method loops through the cached requests and verifies they were all processed and inserted into MongoDB.

The total time it takes the test to run through all 11,000 iterations + validation is about 1 min 32 sec.  
Once complete however, the finalization takes another 18 MINUTES!  

Has anyone seen similarly slow performance when finalizing a test run?  I want to ramp this test up by a factor of 10 or more, but I don't think it would ever finish....

--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.
Reply | Threaded
Open this post in threaded view
|

Re: Performance of "Finishing,..." a parallel test run

Jeff-351
What is it you'd like to look at next?  Profiler snapshot? HeapDump?  Or is there something else I can send after it finally finishes?

It's still running so I may have to kill it and drop the number of iterations to get you a final report.  I can send snapshots/heapdumps now.

Let me know what will be most helpful.

On Fri, Sep 18, 2015 at 10:11 AM, Cédric Beust ♔ <[hidden email]> wrote:
Ah yes, it could very well be the report generation. There have been performance problems there for a while but they only manifest themselves for gigantic test suites, and yours seems to fit the profile.

It will be nice to take a look at the profiler report, although I suspect it will highlight string concatenations as the problem. Just a hunch.


-- 
Cédric


On Fri, Sep 18, 2015 at 8:46 AM, Jeff <[hidden email]> wrote:
I just realized that the "Finishing..." message is coming from my SuiteListener.onFinish() method, and that's all it does (see below), so whatever is happening after this (looks like TestNG Report Generation)

    @Override
    public void onFinish(ISuite suite) {
        System.out.println("Finishing...");
    }

FWIW, it's still running (40 minutes)....

On Fri, Sep 18, 2015 at 9:27 AM, Jeff <[hidden email]> wrote:
At the end of the mvn test run this is what I see:

   ...
Running 109999 iterations ....
Finishing...

and then it hangs (current run approaching 15 minutes) after it printed the "Finishing..." message.  Eventually it does finish.  I'll try attaching some profiler snapshot images.  If that doesn't work, I'll email them to you directly.




On Thu, Sep 17, 2015 at 8:41 PM, Cédric Beust ♔ <[hidden email]> wrote:
Can you clarify what you mean by "finalizing"? Can you run a profiler and find out where these 18 minutes are being spent? It should be easy to track down.



-- 
Cédric


On Thu, Sep 17, 2015 at 3:28 PM, Jeff <[hidden email]> wrote:
Running Maven + Java 8 + TestNG 
I have a DataProvider test that runs 20 threads and processes 11,000 data-driven test instances.

Each iteration does the following:
  • Calls a web service
  • inserts a message on a rabbitmq queue
  • caches the request information for later checking
After all 11,000 were submitted, another method loops through the cached requests and verifies they were all processed and inserted into MongoDB.

The total time it takes the test to run through all 11,000 iterations + validation is about 1 min 32 sec.  
Once complete however, the finalization takes another 18 MINUTES!  

Has anyone seen similarly slow performance when finalizing a test run?  I want to ramp this test up by a factor of 10 or more, but I don't think it would ever finish....

--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.
Reply | Threaded
Open this post in threaded view
|

Re: Performance of "Finishing,..." a parallel test run

Jeff-351
Attached is a simple project that exhibits the behavior that can be easily run.  Maybe it will help.   

On Fri, Sep 18, 2015 at 10:57 AM, Jeff <[hidden email]> wrote:
What is it you'd like to look at next?  Profiler snapshot? HeapDump?  Or is there something else I can send after it finally finishes?

It's still running so I may have to kill it and drop the number of iterations to get you a final report.  I can send snapshots/heapdumps now.

Let me know what will be most helpful.

On Fri, Sep 18, 2015 at 10:11 AM, Cédric Beust ♔ <[hidden email]> wrote:
Ah yes, it could very well be the report generation. There have been performance problems there for a while but they only manifest themselves for gigantic test suites, and yours seems to fit the profile.

It will be nice to take a look at the profiler report, although I suspect it will highlight string concatenations as the problem. Just a hunch.


-- 
Cédric


On Fri, Sep 18, 2015 at 8:46 AM, Jeff <[hidden email]> wrote:
I just realized that the "Finishing..." message is coming from my SuiteListener.onFinish() method, and that's all it does (see below), so whatever is happening after this (looks like TestNG Report Generation)

    @Override
    public void onFinish(ISuite suite) {
        System.out.println("Finishing...");
    }

FWIW, it's still running (40 minutes)....

On Fri, Sep 18, 2015 at 9:27 AM, Jeff <[hidden email]> wrote:
At the end of the mvn test run this is what I see:

   ...
Running 109999 iterations ....
Finishing...

and then it hangs (current run approaching 15 minutes) after it printed the "Finishing..." message.  Eventually it does finish.  I'll try attaching some profiler snapshot images.  If that doesn't work, I'll email them to you directly.




On Thu, Sep 17, 2015 at 8:41 PM, Cédric Beust ♔ <[hidden email]> wrote:
Can you clarify what you mean by "finalizing"? Can you run a profiler and find out where these 18 minutes are being spent? It should be easy to track down.



-- 
Cédric


On Thu, Sep 17, 2015 at 3:28 PM, Jeff <[hidden email]> wrote:
Running Maven + Java 8 + TestNG 
I have a DataProvider test that runs 20 threads and processes 11,000 data-driven test instances.

Each iteration does the following:
  • Calls a web service
  • inserts a message on a rabbitmq queue
  • caches the request information for later checking
After all 11,000 were submitted, another method loops through the cached requests and verifies they were all processed and inserted into MongoDB.

The total time it takes the test to run through all 11,000 iterations + validation is about 1 min 32 sec.  
Once complete however, the finalization takes another 18 MINUTES!  

Has anyone seen similarly slow performance when finalizing a test run?  I want to ramp this test up by a factor of 10 or more, but I don't think it would ever finish....

--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

testng-test.zip (4K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Performance of "Finishing,..." a parallel test run

Krishnan Mahadevan
Jeff,

I took the liberty of tweaking your sample to as below :

public class ParallelTest {

private ITestContext ctx;

@BeforeClass
public void setup(ITestContext ctx) {
this.ctx = ctx;
XmlSuite suite = ctx.getSuite().getXmlSuite();
suite.setDataProviderThreadCount(50);
}

@DataProvider (parallel = true, name = "dataProvider")
public Iterator<Object[]> dataProvider() {
MyData data = new MyData();
return data;
}

@Test (dataProvider = "dataProvider", threadPoolSize = 30, invocationCount = 1)
public void testParallelDataProvider(String iterId) {
Long threadId = Thread.currentThread().getId();
System.out.println(String.format("[tId:%d] ParallelTest.testParallelDataProvider(%s)", threadId, iterId));
ITestResult currentResult = Reporter.getCurrentTestResult();
AtomicInteger counter = (AtomicInteger) currentResult.getAttribute("threadId");
if (counter == null) {
counter = new AtomicInteger();
} else {
counter.incrementAndGet();
}
currentResult.setAttribute("threadId", threadId);
currentResult.setAttribute(Long.toString(threadId), counter);
}

@AfterClass
public void stats() {
long total = 0l;

for (ITestResult result : ctx.getPassedTests().getAllResults()) {
String threadId = (String) result.getAttribute("threadId");
long count = (Long) result.getAttribute(threadId);
System.out.println(String.format(" Thread[%d] : %d iterations", threadId, count));
total += count;
}
System.out.println(String.format("Total iterations: %d", total));
}

public static class MyData implements Iterator<Object[]> {
private static final long MAX = 100000;
private AtomicInteger counter = new AtomicInteger();

@Override
public boolean hasNext() {
return counter.get() < MAX;
}

@Override
public Object[] next() {
int value = counter.getAndIncrement();
return new Object[] {"ID_" + value};
}

@Override
public void remove() {
throw new UnsupportedOperationException();

}
}
}


On running the sample program I am repeatedly encountering OutOfMemoryError. 
After adding MAVEN_OPTS to bump the heap space value I still run into OOM errors.

[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.18.1:test (default-test) on project testng-test: Execution default-test of goal org.apache.maven.plugins:maven-surefire-plugin:2.18.1:test failed: There was an error in the forked process
[ERROR] java.lang.OutOfMemoryError: Java heap space
[ERROR] at java.util.Arrays.copyOf(Arrays.java:2367)
[ERROR] at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:130)
[ERROR] at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:114)
[ERROR] at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:415)
[ERROR] at java.lang.StringBuilder.append(StringBuilder.java:132)
[ERROR] at org.testng.reporters.Files.readFile(Files.java:31)
[ERROR] at org.testng.reporters.Files.readFile(Files.java:22)
[ERROR] at org.testng.reporters.FileStringBuffer.toString(FileStringBuffer.java:143)
[ERROR] at org.testng.reporters.XMLStringBuffer.toXML(XMLStringBuffer.java:337)
[ERROR] at org.testng.reporters.jq.NavigatorPanel.generateMethodList(NavigatorPanel.java:249)
[ERROR] at org.testng.reporters.jq.NavigatorPanel.generateResult(NavigatorPanel.java:115)
[ERROR] at org.testng.reporters.jq.NavigatorPanel.generate(NavigatorPanel.java:70)
[ERROR] at org.testng.reporters.jq.Main.generateReport(Main.java:51)
[ERROR] at org.testng.TestNG.generateReports(TestNG.java:1076)
[ERROR] at org.testng.TestNG.run(TestNG.java:1035)
[ERROR] at org.apache.maven.surefire.testng.TestNGExecutor.run(TestNGExecutor.java:115)
[ERROR] at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.executeSingleClass(TestNGDirectoryTestSuite.java:129)
[ERROR] at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.execute(TestNGDirectoryTestSuite.java:113)
[ERROR] at org.apache.maven.surefire.testng.TestNGProvider.invoke(TestNGProvider.java:111)
[ERROR] at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:203)
[ERROR] at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:155)
[ERROR] at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
[ERROR] -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
krmahadevan@necropolis testng-test $


Thanks & Regards
Krishnan Mahadevan

"All the desirable things in life are either illegal, expensive, fattening or in love with someone else!"
My Scribblings @ http://wakened-cognition.blogspot.com/
My Technical Scribbings @ http://rationaleemotions.wordpress.com/

On Sat, Sep 19, 2015 at 1:24 AM, Jeff <[hidden email]> wrote:
Attached is a simple project that exhibits the behavior that can be easily run.  Maybe it will help.   

On Fri, Sep 18, 2015 at 10:57 AM, Jeff <[hidden email]> wrote:
What is it you'd like to look at next?  Profiler snapshot? HeapDump?  Or is there something else I can send after it finally finishes?

It's still running so I may have to kill it and drop the number of iterations to get you a final report.  I can send snapshots/heapdumps now.

Let me know what will be most helpful.

On Fri, Sep 18, 2015 at 10:11 AM, Cédric Beust ♔ <[hidden email]> wrote:
Ah yes, it could very well be the report generation. There have been performance problems there for a while but they only manifest themselves for gigantic test suites, and yours seems to fit the profile.

It will be nice to take a look at the profiler report, although I suspect it will highlight string concatenations as the problem. Just a hunch.


-- 
Cédric


On Fri, Sep 18, 2015 at 8:46 AM, Jeff <[hidden email]> wrote:
I just realized that the "Finishing..." message is coming from my SuiteListener.onFinish() method, and that's all it does (see below), so whatever is happening after this (looks like TestNG Report Generation)

    @Override
    public void onFinish(ISuite suite) {
        System.out.println("Finishing...");
    }

FWIW, it's still running (40 minutes)....

On Fri, Sep 18, 2015 at 9:27 AM, Jeff <[hidden email]> wrote:
At the end of the mvn test run this is what I see:

   ...
Running 109999 iterations ....
Finishing...

and then it hangs (current run approaching 15 minutes) after it printed the "Finishing..." message.  Eventually it does finish.  I'll try attaching some profiler snapshot images.  If that doesn't work, I'll email them to you directly.




On Thu, Sep 17, 2015 at 8:41 PM, Cédric Beust ♔ <[hidden email]> wrote:
Can you clarify what you mean by "finalizing"? Can you run a profiler and find out where these 18 minutes are being spent? It should be easy to track down.



-- 
Cédric


On Thu, Sep 17, 2015 at 3:28 PM, Jeff <[hidden email]> wrote:
Running Maven + Java 8 + TestNG 
I have a DataProvider test that runs 20 threads and processes 11,000 data-driven test instances.

Each iteration does the following:
  • Calls a web service
  • inserts a message on a rabbitmq queue
  • caches the request information for later checking
After all 11,000 were submitted, another method loops through the cached requests and verifies they were all processed and inserted into MongoDB.

The total time it takes the test to run through all 11,000 iterations + validation is about 1 min 32 sec.  
Once complete however, the finalization takes another 18 MINUTES!  

Has anyone seen similarly slow performance when finalizing a test run?  I want to ramp this test up by a factor of 10 or more, but I don't think it would ever finish....

--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.
Reply | Threaded
Open this post in threaded view
|

Re: Performance of "Finishing,..." a parallel test run

Cédric Beust ♔-2
Thanks, Krishnan, this pretty much confirms my suspicion. I'll have to take a closer look but I'm guessing a reporter is trying to read or write a huge file in memory while it should do so in chunks.

-- 
Cédric


On Fri, Sep 18, 2015 at 10:15 PM, Krishnan Mahadevan <[hidden email]> wrote:
Jeff,

I took the liberty of tweaking your sample to as below :

public class ParallelTest {

private ITestContext ctx;

@BeforeClass
public void setup(ITestContext ctx) {
this.ctx = ctx;
XmlSuite suite = ctx.getSuite().getXmlSuite();
suite.setDataProviderThreadCount(50);
}

@DataProvider (parallel = true, name = "dataProvider")
public Iterator<Object[]> dataProvider() {
MyData data = new MyData();
return data;
}

@Test (dataProvider = "dataProvider", threadPoolSize = 30, invocationCount = 1)
public void testParallelDataProvider(String iterId) {
Long threadId = Thread.currentThread().getId();
System.out.println(String.format("[tId:%d] ParallelTest.testParallelDataProvider(%s)", threadId, iterId));
ITestResult currentResult = Reporter.getCurrentTestResult();
AtomicInteger counter = (AtomicInteger) currentResult.getAttribute("threadId");
if (counter == null) {
counter = new AtomicInteger();
} else {
counter.incrementAndGet();
}
currentResult.setAttribute("threadId", threadId);
currentResult.setAttribute(Long.toString(threadId), counter);
}

@AfterClass
public void stats() {
long total = 0l;

for (ITestResult result : ctx.getPassedTests().getAllResults()) {
String threadId = (String) result.getAttribute("threadId");
long count = (Long) result.getAttribute(threadId);
System.out.println(String.format(" Thread[%d] : %d iterations", threadId, count));
total += count;
}
System.out.println(String.format("Total iterations: %d", total));
}

public static class MyData implements Iterator<Object[]> {
private static final long MAX = 100000;
private AtomicInteger counter = new AtomicInteger();

@Override
public boolean hasNext() {
return counter.get() < MAX;
}

@Override
public Object[] next() {
int value = counter.getAndIncrement();
return new Object[] {"ID_" + value};
}

@Override
public void remove() {
throw new UnsupportedOperationException();

}
}
}


On running the sample program I am repeatedly encountering OutOfMemoryError. 
After adding MAVEN_OPTS to bump the heap space value I still run into OOM errors.

[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.18.1:test (default-test) on project testng-test: Execution default-test of goal org.apache.maven.plugins:maven-surefire-plugin:2.18.1:test failed: There was an error in the forked process
[ERROR] java.lang.OutOfMemoryError: Java heap space
[ERROR] at java.util.Arrays.copyOf(Arrays.java:2367)
[ERROR] at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:130)
[ERROR] at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:114)
[ERROR] at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:415)
[ERROR] at java.lang.StringBuilder.append(StringBuilder.java:132)
[ERROR] at org.testng.reporters.Files.readFile(Files.java:31)
[ERROR] at org.testng.reporters.Files.readFile(Files.java:22)
[ERROR] at org.testng.reporters.FileStringBuffer.toString(FileStringBuffer.java:143)
[ERROR] at org.testng.reporters.XMLStringBuffer.toXML(XMLStringBuffer.java:337)
[ERROR] at org.testng.reporters.jq.NavigatorPanel.generateMethodList(NavigatorPanel.java:249)
[ERROR] at org.testng.reporters.jq.NavigatorPanel.generateResult(NavigatorPanel.java:115)
[ERROR] at org.testng.reporters.jq.NavigatorPanel.generate(NavigatorPanel.java:70)
[ERROR] at org.testng.reporters.jq.Main.generateReport(Main.java:51)
[ERROR] at org.testng.TestNG.generateReports(TestNG.java:1076)
[ERROR] at org.testng.TestNG.run(TestNG.java:1035)
[ERROR] at org.apache.maven.surefire.testng.TestNGExecutor.run(TestNGExecutor.java:115)
[ERROR] at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.executeSingleClass(TestNGDirectoryTestSuite.java:129)
[ERROR] at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.execute(TestNGDirectoryTestSuite.java:113)
[ERROR] at org.apache.maven.surefire.testng.TestNGProvider.invoke(TestNGProvider.java:111)
[ERROR] at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:203)
[ERROR] at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:155)
[ERROR] at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
[ERROR] -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
krmahadevan@necropolis testng-test $


Thanks & Regards
Krishnan Mahadevan

"All the desirable things in life are either illegal, expensive, fattening or in love with someone else!"
My Scribblings @ http://wakened-cognition.blogspot.com/
My Technical Scribbings @ http://rationaleemotions.wordpress.com/

On Sat, Sep 19, 2015 at 1:24 AM, Jeff <[hidden email]> wrote:
Attached is a simple project that exhibits the behavior that can be easily run.  Maybe it will help.   

On Fri, Sep 18, 2015 at 10:57 AM, Jeff <[hidden email]> wrote:
What is it you'd like to look at next?  Profiler snapshot? HeapDump?  Or is there something else I can send after it finally finishes?

It's still running so I may have to kill it and drop the number of iterations to get you a final report.  I can send snapshots/heapdumps now.

Let me know what will be most helpful.

On Fri, Sep 18, 2015 at 10:11 AM, Cédric Beust ♔ <[hidden email]> wrote:
Ah yes, it could very well be the report generation. There have been performance problems there for a while but they only manifest themselves for gigantic test suites, and yours seems to fit the profile.

It will be nice to take a look at the profiler report, although I suspect it will highlight string concatenations as the problem. Just a hunch.


-- 
Cédric


On Fri, Sep 18, 2015 at 8:46 AM, Jeff <[hidden email]> wrote:
I just realized that the "Finishing..." message is coming from my SuiteListener.onFinish() method, and that's all it does (see below), so whatever is happening after this (looks like TestNG Report Generation)

    @Override
    public void onFinish(ISuite suite) {
        System.out.println("Finishing...");
    }

FWIW, it's still running (40 minutes)....

On Fri, Sep 18, 2015 at 9:27 AM, Jeff <[hidden email]> wrote:
At the end of the mvn test run this is what I see:

   ...
Running 109999 iterations ....
Finishing...

and then it hangs (current run approaching 15 minutes) after it printed the "Finishing..." message.  Eventually it does finish.  I'll try attaching some profiler snapshot images.  If that doesn't work, I'll email them to you directly.




On Thu, Sep 17, 2015 at 8:41 PM, Cédric Beust ♔ <[hidden email]> wrote:
Can you clarify what you mean by "finalizing"? Can you run a profiler and find out where these 18 minutes are being spent? It should be easy to track down.



-- 
Cédric


On Thu, Sep 17, 2015 at 3:28 PM, Jeff <[hidden email]> wrote:
Running Maven + Java 8 + TestNG 
I have a DataProvider test that runs 20 threads and processes 11,000 data-driven test instances.

Each iteration does the following:
  • Calls a web service
  • inserts a message on a rabbitmq queue
  • caches the request information for later checking
After all 11,000 were submitted, another method loops through the cached requests and verifies they were all processed and inserted into MongoDB.

The total time it takes the test to run through all 11,000 iterations + validation is about 1 min 32 sec.  
Once complete however, the finalization takes another 18 MINUTES!  

Has anyone seen similarly slow performance when finalizing a test run?  I want to ramp this test up by a factor of 10 or more, but I don't think it would ever finish....

--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.
Reply | Threaded
Open this post in threaded view
|

Re: Performance of "Finishing,..." a parallel test run

Jeff-351
Thanks for posting the refactored version.  I'll add that to my "101,000 ways to write a test class" example library. :-)

I'm at a loss to understand why any file in the test report be so large it wouldn't fit into memory.  In my actual test class, I'm reading in data from 3 different sources (MongoDB JSON documents and 2 MySQL schemas returning many pojos representing the query results and using these objects to generate my 110,000 object dataset for the DataProvider.  All this is fitting into memory just fine.

In 12 GB of RAM you can fit a really big XML document.  Could it instead be rereading the same document again and again as its generating the test report? (Sorry, just spitballing theories).


On Sat, Sep 19, 2015 at 12:04 AM, Cédric Beust ♔ <[hidden email]> wrote:
Thanks, Krishnan, this pretty much confirms my suspicion. I'll have to take a closer look but I'm guessing a reporter is trying to read or write a huge file in memory while it should do so in chunks.

-- 
Cédric


On Fri, Sep 18, 2015 at 10:15 PM, Krishnan Mahadevan <[hidden email]> wrote:
Jeff,

I took the liberty of tweaking your sample to as below :

public class ParallelTest {

private ITestContext ctx;

@BeforeClass
public void setup(ITestContext ctx) {
this.ctx = ctx;
XmlSuite suite = ctx.getSuite().getXmlSuite();
suite.setDataProviderThreadCount(50);
}

@DataProvider (parallel = true, name = "dataProvider")
public Iterator<Object[]> dataProvider() {
MyData data = new MyData();
return data;
}

@Test (dataProvider = "dataProvider", threadPoolSize = 30, invocationCount = 1)
public void testParallelDataProvider(String iterId) {
Long threadId = Thread.currentThread().getId();
System.out.println(String.format("[tId:%d] ParallelTest.testParallelDataProvider(%s)", threadId, iterId));
ITestResult currentResult = Reporter.getCurrentTestResult();
AtomicInteger counter = (AtomicInteger) currentResult.getAttribute("threadId");
if (counter == null) {
counter = new AtomicInteger();
} else {
counter.incrementAndGet();
}
currentResult.setAttribute("threadId", threadId);
currentResult.setAttribute(Long.toString(threadId), counter);
}

@AfterClass
public void stats() {
long total = 0l;

for (ITestResult result : ctx.getPassedTests().getAllResults()) {
String threadId = (String) result.getAttribute("threadId");
long count = (Long) result.getAttribute(threadId);
System.out.println(String.format(" Thread[%d] : %d iterations", threadId, count));
total += count;
}
System.out.println(String.format("Total iterations: %d", total));
}

public static class MyData implements Iterator<Object[]> {
private static final long MAX = 100000;
private AtomicInteger counter = new AtomicInteger();

@Override
public boolean hasNext() {
return counter.get() < MAX;
}

@Override
public Object[] next() {
int value = counter.getAndIncrement();
return new Object[] {"ID_" + value};
}

@Override
public void remove() {
throw new UnsupportedOperationException();

}
}
}


On running the sample program I am repeatedly encountering OutOfMemoryError. 
After adding MAVEN_OPTS to bump the heap space value I still run into OOM errors.

[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.18.1:test (default-test) on project testng-test: Execution default-test of goal org.apache.maven.plugins:maven-surefire-plugin:2.18.1:test failed: There was an error in the forked process
[ERROR] java.lang.OutOfMemoryError: Java heap space
[ERROR] at java.util.Arrays.copyOf(Arrays.java:2367)
[ERROR] at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:130)
[ERROR] at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:114)
[ERROR] at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:415)
[ERROR] at java.lang.StringBuilder.append(StringBuilder.java:132)
[ERROR] at org.testng.reporters.Files.readFile(Files.java:31)
[ERROR] at org.testng.reporters.Files.readFile(Files.java:22)
[ERROR] at org.testng.reporters.FileStringBuffer.toString(FileStringBuffer.java:143)
[ERROR] at org.testng.reporters.XMLStringBuffer.toXML(XMLStringBuffer.java:337)
[ERROR] at org.testng.reporters.jq.NavigatorPanel.generateMethodList(NavigatorPanel.java:249)
[ERROR] at org.testng.reporters.jq.NavigatorPanel.generateResult(NavigatorPanel.java:115)
[ERROR] at org.testng.reporters.jq.NavigatorPanel.generate(NavigatorPanel.java:70)
[ERROR] at org.testng.reporters.jq.Main.generateReport(Main.java:51)
[ERROR] at org.testng.TestNG.generateReports(TestNG.java:1076)
[ERROR] at org.testng.TestNG.run(TestNG.java:1035)
[ERROR] at org.apache.maven.surefire.testng.TestNGExecutor.run(TestNGExecutor.java:115)
[ERROR] at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.executeSingleClass(TestNGDirectoryTestSuite.java:129)
[ERROR] at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.execute(TestNGDirectoryTestSuite.java:113)
[ERROR] at org.apache.maven.surefire.testng.TestNGProvider.invoke(TestNGProvider.java:111)
[ERROR] at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:203)
[ERROR] at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:155)
[ERROR] at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
[ERROR] -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
krmahadevan@necropolis testng-test $


Thanks & Regards
Krishnan Mahadevan

"All the desirable things in life are either illegal, expensive, fattening or in love with someone else!"
My Scribblings @ http://wakened-cognition.blogspot.com/
My Technical Scribbings @ http://rationaleemotions.wordpress.com/

On Sat, Sep 19, 2015 at 1:24 AM, Jeff <[hidden email]> wrote:
Attached is a simple project that exhibits the behavior that can be easily run.  Maybe it will help.   

On Fri, Sep 18, 2015 at 10:57 AM, Jeff <[hidden email]> wrote:
What is it you'd like to look at next?  Profiler snapshot? HeapDump?  Or is there something else I can send after it finally finishes?

It's still running so I may have to kill it and drop the number of iterations to get you a final report.  I can send snapshots/heapdumps now.

Let me know what will be most helpful.

On Fri, Sep 18, 2015 at 10:11 AM, Cédric Beust ♔ <[hidden email]> wrote:
Ah yes, it could very well be the report generation. There have been performance problems there for a while but they only manifest themselves for gigantic test suites, and yours seems to fit the profile.

It will be nice to take a look at the profiler report, although I suspect it will highlight string concatenations as the problem. Just a hunch.


-- 
Cédric


On Fri, Sep 18, 2015 at 8:46 AM, Jeff <[hidden email]> wrote:
I just realized that the "Finishing..." message is coming from my SuiteListener.onFinish() method, and that's all it does (see below), so whatever is happening after this (looks like TestNG Report Generation)

    @Override
    public void onFinish(ISuite suite) {
        System.out.println("Finishing...");
    }

FWIW, it's still running (40 minutes)....

On Fri, Sep 18, 2015 at 9:27 AM, Jeff <[hidden email]> wrote:
At the end of the mvn test run this is what I see:

   ...
Running 109999 iterations ....
Finishing...

and then it hangs (current run approaching 15 minutes) after it printed the "Finishing..." message.  Eventually it does finish.  I'll try attaching some profiler snapshot images.  If that doesn't work, I'll email them to you directly.




On Thu, Sep 17, 2015 at 8:41 PM, Cédric Beust ♔ <[hidden email]> wrote:
Can you clarify what you mean by "finalizing"? Can you run a profiler and find out where these 18 minutes are being spent? It should be easy to track down.



-- 
Cédric


On Thu, Sep 17, 2015 at 3:28 PM, Jeff <[hidden email]> wrote:
Running Maven + Java 8 + TestNG 
I have a DataProvider test that runs 20 threads and processes 11,000 data-driven test instances.

Each iteration does the following:
  • Calls a web service
  • inserts a message on a rabbitmq queue
  • caches the request information for later checking
After all 11,000 were submitted, another method loops through the cached requests and verifies they were all processed and inserted into MongoDB.

The total time it takes the test to run through all 11,000 iterations + validation is about 1 min 32 sec.  
Once complete however, the finalization takes another 18 MINUTES!  

Has anyone seen similarly slow performance when finalizing a test run?  I want to ramp this test up by a factor of 10 or more, but I don't think it would ever finish....

--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.
Reply | Threaded
Open this post in threaded view
|

Re: Performance of "Finishing,..." a parallel test run

Cédric Beust ♔-2
You are welcome to put a breakpoint there and find out yourself :)


-- 
Cédric


On Sat, Sep 19, 2015 at 7:59 PM, Jeff <[hidden email]> wrote:
Thanks for posting the refactored version.  I'll add that to my "101,000 ways to write a test class" example library. :-)

I'm at a loss to understand why any file in the test report be so large it wouldn't fit into memory.  In my actual test class, I'm reading in data from 3 different sources (MongoDB JSON documents and 2 MySQL schemas returning many pojos representing the query results and using these objects to generate my 110,000 object dataset for the DataProvider.  All this is fitting into memory just fine.

In 12 GB of RAM you can fit a really big XML document.  Could it instead be rereading the same document again and again as its generating the test report? (Sorry, just spitballing theories).


On Sat, Sep 19, 2015 at 12:04 AM, Cédric Beust ♔ <[hidden email]> wrote:
Thanks, Krishnan, this pretty much confirms my suspicion. I'll have to take a closer look but I'm guessing a reporter is trying to read or write a huge file in memory while it should do so in chunks.

-- 
Cédric


On Fri, Sep 18, 2015 at 10:15 PM, Krishnan Mahadevan <[hidden email]> wrote:
Jeff,

I took the liberty of tweaking your sample to as below :

public class ParallelTest {

private ITestContext ctx;

@BeforeClass
public void setup(ITestContext ctx) {
this.ctx = ctx;
XmlSuite suite = ctx.getSuite().getXmlSuite();
suite.setDataProviderThreadCount(50);
}

@DataProvider (parallel = true, name = "dataProvider")
public Iterator<Object[]> dataProvider() {
MyData data = new MyData();
return data;
}

@Test (dataProvider = "dataProvider", threadPoolSize = 30, invocationCount = 1)
public void testParallelDataProvider(String iterId) {
Long threadId = Thread.currentThread().getId();
System.out.println(String.format("[tId:%d] ParallelTest.testParallelDataProvider(%s)", threadId, iterId));
ITestResult currentResult = Reporter.getCurrentTestResult();
AtomicInteger counter = (AtomicInteger) currentResult.getAttribute("threadId");
if (counter == null) {
counter = new AtomicInteger();
} else {
counter.incrementAndGet();
}
currentResult.setAttribute("threadId", threadId);
currentResult.setAttribute(Long.toString(threadId), counter);
}

@AfterClass
public void stats() {
long total = 0l;

for (ITestResult result : ctx.getPassedTests().getAllResults()) {
String threadId = (String) result.getAttribute("threadId");
long count = (Long) result.getAttribute(threadId);
System.out.println(String.format(" Thread[%d] : %d iterations", threadId, count));
total += count;
}
System.out.println(String.format("Total iterations: %d", total));
}

public static class MyData implements Iterator<Object[]> {
private static final long MAX = 100000;
private AtomicInteger counter = new AtomicInteger();

@Override
public boolean hasNext() {
return counter.get() < MAX;
}

@Override
public Object[] next() {
int value = counter.getAndIncrement();
return new Object[] {"ID_" + value};
}

@Override
public void remove() {
throw new UnsupportedOperationException();

}
}
}


On running the sample program I am repeatedly encountering OutOfMemoryError. 
After adding MAVEN_OPTS to bump the heap space value I still run into OOM errors.

[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:2.18.1:test (default-test) on project testng-test: Execution default-test of goal org.apache.maven.plugins:maven-surefire-plugin:2.18.1:test failed: There was an error in the forked process
[ERROR] java.lang.OutOfMemoryError: Java heap space
[ERROR] at java.util.Arrays.copyOf(Arrays.java:2367)
[ERROR] at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:130)
[ERROR] at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:114)
[ERROR] at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:415)
[ERROR] at java.lang.StringBuilder.append(StringBuilder.java:132)
[ERROR] at org.testng.reporters.Files.readFile(Files.java:31)
[ERROR] at org.testng.reporters.Files.readFile(Files.java:22)
[ERROR] at org.testng.reporters.FileStringBuffer.toString(FileStringBuffer.java:143)
[ERROR] at org.testng.reporters.XMLStringBuffer.toXML(XMLStringBuffer.java:337)
[ERROR] at org.testng.reporters.jq.NavigatorPanel.generateMethodList(NavigatorPanel.java:249)
[ERROR] at org.testng.reporters.jq.NavigatorPanel.generateResult(NavigatorPanel.java:115)
[ERROR] at org.testng.reporters.jq.NavigatorPanel.generate(NavigatorPanel.java:70)
[ERROR] at org.testng.reporters.jq.Main.generateReport(Main.java:51)
[ERROR] at org.testng.TestNG.generateReports(TestNG.java:1076)
[ERROR] at org.testng.TestNG.run(TestNG.java:1035)
[ERROR] at org.apache.maven.surefire.testng.TestNGExecutor.run(TestNGExecutor.java:115)
[ERROR] at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.executeSingleClass(TestNGDirectoryTestSuite.java:129)
[ERROR] at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.execute(TestNGDirectoryTestSuite.java:113)
[ERROR] at org.apache.maven.surefire.testng.TestNGProvider.invoke(TestNGProvider.java:111)
[ERROR] at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:203)
[ERROR] at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:155)
[ERROR] at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103)
[ERROR] -> [Help 1]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
krmahadevan@necropolis testng-test $


Thanks & Regards
Krishnan Mahadevan

"All the desirable things in life are either illegal, expensive, fattening or in love with someone else!"
My Scribblings @ http://wakened-cognition.blogspot.com/
My Technical Scribbings @ http://rationaleemotions.wordpress.com/

On Sat, Sep 19, 2015 at 1:24 AM, Jeff <[hidden email]> wrote:
Attached is a simple project that exhibits the behavior that can be easily run.  Maybe it will help.   

On Fri, Sep 18, 2015 at 10:57 AM, Jeff <[hidden email]> wrote:
What is it you'd like to look at next?  Profiler snapshot? HeapDump?  Or is there something else I can send after it finally finishes?

It's still running so I may have to kill it and drop the number of iterations to get you a final report.  I can send snapshots/heapdumps now.

Let me know what will be most helpful.

On Fri, Sep 18, 2015 at 10:11 AM, Cédric Beust ♔ <[hidden email]> wrote:
Ah yes, it could very well be the report generation. There have been performance problems there for a while but they only manifest themselves for gigantic test suites, and yours seems to fit the profile.

It will be nice to take a look at the profiler report, although I suspect it will highlight string concatenations as the problem. Just a hunch.


-- 
Cédric


On Fri, Sep 18, 2015 at 8:46 AM, Jeff <[hidden email]> wrote:
I just realized that the "Finishing..." message is coming from my SuiteListener.onFinish() method, and that's all it does (see below), so whatever is happening after this (looks like TestNG Report Generation)

    @Override
    public void onFinish(ISuite suite) {
        System.out.println("Finishing...");
    }

FWIW, it's still running (40 minutes)....

On Fri, Sep 18, 2015 at 9:27 AM, Jeff <[hidden email]> wrote:
At the end of the mvn test run this is what I see:

   ...
Running 109999 iterations ....
Finishing...

and then it hangs (current run approaching 15 minutes) after it printed the "Finishing..." message.  Eventually it does finish.  I'll try attaching some profiler snapshot images.  If that doesn't work, I'll email them to you directly.




On Thu, Sep 17, 2015 at 8:41 PM, Cédric Beust ♔ <[hidden email]> wrote:
Can you clarify what you mean by "finalizing"? Can you run a profiler and find out where these 18 minutes are being spent? It should be easy to track down.



-- 
Cédric


On Thu, Sep 17, 2015 at 3:28 PM, Jeff <[hidden email]> wrote:
Running Maven + Java 8 + TestNG 
I have a DataProvider test that runs 20 threads and processes 11,000 data-driven test instances.

Each iteration does the following:
  • Calls a web service
  • inserts a message on a rabbitmq queue
  • caches the request information for later checking
After all 11,000 were submitted, another method loops through the cached requests and verifies they were all processed and inserted into MongoDB.

The total time it takes the test to run through all 11,000 iterations + validation is about 1 min 32 sec.  
Once complete however, the finalization takes another 18 MINUTES!  

Has anyone seen similarly slow performance when finalizing a test run?  I want to ramp this test up by a factor of 10 or more, but I don't think it would ever finish....

--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.
Nat
Reply | Threaded
Open this post in threaded view
|

Re: Performance of "Finishing,..." a parallel test run

Nat
Try running maven by turning off most of the reports since they are pretty much unnecessary anyway.

      <configuration>
          <properties>
            <property>
              <name>usedefaultlisteners</name>
              <value>false</value>
            </property>
            <property>
              <name>reporter</name>
              <value>add whatever the report you really need here</value>
            </property>
          </properties>
        </configuration>

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.
Reply | Threaded
Open this post in threaded view
|

Re: Performance of "Finishing,..." a parallel test run

Jeff-351
Awesome! I'm struggling to know what to put in the "add whatever the report you really need here" is value field.  I've only ever used the default reporting.  In looking at the org.testng.reporters package there are a bunch of classes that I assume I could specify, but I'm not sure which to use.  I'm open to suggestions.

I really only need a simple pass/fail/skipped/total type report with possibly the failure messages.  Currently the  reports are published via Jenkins, but soon, will be also published in our GoCD continuous deployment process.

Thanks!

On Sun, Nov 1, 2015 at 11:31 PM, Nat <[hidden email]> wrote:
Try running maven by turning off most of the reports since they are pretty much unnecessary anyway.

      <configuration>
          <properties>
            <property>
              <name>usedefaultlisteners</name>
              <value>false</value>
            </property>
            <property>
              <name>reporter</name>
              <value>add whatever the report you really need here</value>
            </property>
          </properties>
        </configuration>

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.
Nat
Reply | Threaded
Open this post in threaded view
|

Re: Performance of "Finishing,..." a parallel test run

Nat
If you just need a simple pass/fail/skipped/total report, I believe that org.testng.reporters.XMLReporter should be good enough. Note that you might need to use "-reporter" instead of "reporter" for the configuration to work in maven.

On Monday, November 2, 2015 at 9:52:19 AM UTC-8, Jeff wrote:
Awesome! I'm struggling to know what to put in the "add whatever the report you really need here" is value field.  I've only ever used the default reporting.  In looking at the org.testng.reporters package there are a bunch of classes that I assume I could specify, but I'm not sure which to use.  I'm open to suggestions.

I really only need a simple pass/fail/skipped/total type report with possibly the failure messages.  Currently the  reports are published via Jenkins, but soon, will be also published in our GoCD continuous deployment process.

Thanks!

On Sun, Nov 1, 2015 at 11:31 PM, Nat <<a href="javascript:" target="_blank" gdf-obfuscated-mailto="JmQ7fKR_DgAJ" rel="nofollow" onmousedown="this.href=&#39;javascript:&#39;;return true;" onclick="this.href=&#39;javascript:&#39;;return true;">nat....@...> wrote:
Try running maven by turning off most of the reports since they are pretty much unnecessary anyway.

      <configuration>
          <properties>
            <property>
              <name>usedefaultlisteners</name>
              <value>false</value>
            </property>
            <property>
              <name>reporter</name>
              <value>add whatever the report you really need here</value>
            </property>
          </properties>
        </configuration>

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to <a href="javascript:" target="_blank" gdf-obfuscated-mailto="JmQ7fKR_DgAJ" rel="nofollow" onmousedown="this.href=&#39;javascript:&#39;;return true;" onclick="this.href=&#39;javascript:&#39;;return true;">testng-users...@googlegroups.com.
To post to this group, send email to <a href="javascript:" target="_blank" gdf-obfuscated-mailto="JmQ7fKR_DgAJ" rel="nofollow" onmousedown="this.href=&#39;javascript:&#39;;return true;" onclick="this.href=&#39;javascript:&#39;;return true;">testng...@....
Visit this group at <a href="http://groups.google.com/group/testng-users" target="_blank" rel="nofollow" onmousedown="this.href=&#39;http://groups.google.com/group/testng-users&#39;;return true;" onclick="this.href=&#39;http://groups.google.com/group/testng-users&#39;;return true;">http://groups.google.com/group/testng-users.
For more options, visit <a href="https://groups.google.com/d/optout" target="_blank" rel="nofollow" onmousedown="this.href=&#39;https://groups.google.com/d/optout&#39;;return true;" onclick="this.href=&#39;https://groups.google.com/d/optout&#39;;return true;">https://groups.google.com/d/optout.



--
Jeff Vincent
See my LinkedIn profile at:
<a href="http://www.linkedin.com/in/rjeffreyvincent" target="_blank" rel="nofollow" onmousedown="this.href=&#39;http://www.google.com/url?q\75http%3A%2F%2Fwww.linkedin.com%2Fin%2Frjeffreyvincent\46sa\75D\46sntz\0751\46usg\75AFQjCNFJszVU3e8UPeGdKd7SrNZhMsseiw&#39;;return true;" onclick="this.href=&#39;http://www.google.com/url?q\75http%3A%2F%2Fwww.linkedin.com%2Fin%2Frjeffreyvincent\46sa\75D\46sntz\0751\46usg\75AFQjCNFJszVU3e8UPeGdKd7SrNZhMsseiw&#39;;return true;">http://www.linkedin.com/in/rjeffreyvincent

--
You received this message because you are subscribed to the Google Groups "testng-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to [hidden email].
To post to this group, send email to [hidden email].
Visit this group at http://groups.google.com/group/testng-users.
For more options, visit https://groups.google.com/d/optout.