/*
* CDDL HEADER START
*
* The contents of this file are subject to the terms of the
* Common Development and Distribution License, Version 1.0 only
* (the "License"). You may not use this file except in compliance
* with the License.
*
* You can obtain a copy of the license at legal-notices/CDDLv1_0.txt
* or http://forgerock.org/license/CDDLv1.0.html.
* See the License for the specific language governing permissions
* and limitations under the License.
*
* When distributing Covered Code, include this CDDL HEADER in each
* file and include the License file at legal-notices/CDDLv1_0.txt.
* If applicable, add the following below this CDDL HEADER, with the
* fields enclosed by brackets "[]" replaced with your own identifying
* information:
* Portions Copyright [yyyy] [name of copyright owner]
*
* CDDL HEADER END
*
*
* Copyright 2008 Sun Microsystems, Inc.
* Portions Copyright 2013-2015 ForgeRock AS.
*/
package org.opends.server;
import java.io.File;
import java.io.FileNotFoundException;
import java.io.FileOutputStream;
import java.io.PrintStream;
import java.lang.annotation.Annotation;
import java.lang.reflect.InvocationTargetException;
import java.lang.reflect.Method;
import java.text.SimpleDateFormat;
import java.util.*;
import org.testng.*;
import org.testng.annotations.DataProvider;
import org.testng.annotations.Test;
import org.testng.xml.XmlSuite;
import static org.opends.server.TestCaseUtils.*;
import static org.opends.server.util.ServerConstants.*;
/**
* This class is our replacement for the test results that TestNG generates.
* It prints out test to the console as they happen.
*/
@SuppressWarnings("javadoc")
public class TestListener extends TestListenerAdapter implements IReporter {
private static final String REPORT_FILE_NAME = "results.txt";
/**
* This is used to communicate with build.xml. So that even when a test fails,
* we can do the coverage report before failing the build.
*/
private static final String ANT_TESTS_FAILED_FILE_NAME = ".tests-failed-marker";
private final StringBuilder _bufferedTestFailures = new StringBuilder();
private static final String PROPERTY_TEST_PROGRESS = "test.progress";
private static final String TEST_PROGRESS_NONE = "none";
private static final String TEST_PROGRESS_ALL = "all";
private static final String TEST_PROGRESS_DEFAULT = "default";
private static final String TEST_PROGRESS_TIME = "time";
private static final String TEST_PROGRESS_TEST_COUNT = "count";
private static final String TEST_PROGRESS_MEMORY = "memory";
/** Hidden for now, since it's not useful to most developers. */
private static final String TEST_PROGRESS_MEMORY_GCS = "gcs";
private static final String TEST_PROGRESS_RESTARTS = "restarts";
private static final String TEST_PROGRESS_THREAD_COUNT = "threadcount";
private static final String TEST_PROGRESS_THREAD_CHANGE = "threadchange";
private static final SimpleDateFormat TEST_PROGESS_TIME_FORMAT = new SimpleDateFormat(
"dd/MMM/yyyy:HH:mm:ss Z");
private boolean doProgressNone;
private boolean doProgressTime = true;
private boolean doProgressTestCount = true;
private boolean doProgressMemory;
private boolean doProgressMemoryGcs;
private boolean doProgressRestarts = true;
private boolean doProgressThreadCount;
private boolean doProgressThreadChange;
private void initializeProgressVars() {
String prop = System.getProperty(PROPERTY_TEST_PROGRESS);
if (prop == null) {
return;
}
prop = prop.toLowerCase();
List<String> progressValues = Arrays.asList(prop.split("\\s*\\W+\\s*"));
if (prop.length() == 0 || progressValues.isEmpty()) {
// Accept the defaults
} else if (progressValues.contains(TEST_PROGRESS_NONE)) {
doProgressNone = true;
doProgressTime = false;
doProgressTestCount = false;
doProgressMemory = false;
doProgressMemoryGcs = false;
doProgressRestarts = false;
doProgressThreadCount = false;
doProgressThreadChange = false;
} else if (progressValues.contains(TEST_PROGRESS_ALL)) {
doProgressNone = false;
doProgressTime = true;
doProgressTestCount = true;
doProgressMemory = true;
doProgressMemoryGcs = true;
doProgressRestarts = true;
doProgressThreadCount = true;
doProgressThreadChange = true;
} else {
doProgressNone = false;
doProgressTime = progressValues.contains(TEST_PROGRESS_TIME);
doProgressTestCount = progressValues.contains(TEST_PROGRESS_TEST_COUNT);
doProgressMemory = progressValues.contains(TEST_PROGRESS_MEMORY);
doProgressMemoryGcs = progressValues.contains(TEST_PROGRESS_MEMORY_GCS);
doProgressRestarts = progressValues.contains(TEST_PROGRESS_RESTARTS);
doProgressThreadCount = progressValues.contains(TEST_PROGRESS_THREAD_COUNT);
doProgressThreadChange = progressValues.contains(TEST_PROGRESS_THREAD_CHANGE);
// If we were asked to do the defaults, then restore anything that's on by default
if (progressValues.contains(TEST_PROGRESS_DEFAULT)) {
doProgressTime = true;
doProgressTestCount = true;
doProgressRestarts = true;
}
}
}
public TestListener() throws Exception {
initializeProgressVars();
}
private static final String DIVIDER_LINE = "-------------------------------------------------------------------------------" + EOL;
@Override
public void onStart(ITestContext testContext) {
super.onStart(testContext);
// Delete the previous report if it's there.
new File(testContext.getOutputDirectory(), REPORT_FILE_NAME).delete();
}
@Override
public void generateReport(List<XmlSuite> xmlSuites, List<ISuite> suites, String outputDirectory) {
File outputDir = new File(outputDirectory);
if (!outputDir.exists()) {
outputDir.mkdir();
}
File reportFile = new File(outputDirectory, REPORT_FILE_NAME);
writeReportToFile(reportFile);
writeReportToScreen(reportFile);
writeAntTestsFailedMarker(outputDirectory);
}
private void writeAntTestsFailedMarker(String outputDirectory) {
// Signal 'ant' that all of the tests passed by removing this
// special file.
if (countTestsWithStatus(ITestResult.FAILURE) == 0
&& countTestsWithStatus(ITestResult.SKIP) == 0)
{
new File(outputDirectory, ANT_TESTS_FAILED_FILE_NAME).delete();
}
}
private void writeReportToFile(File reportFile) {
PrintStream reportStream = null;
try {
reportStream = new PrintStream(new FileOutputStream(reportFile));
} catch (FileNotFoundException e) {
originalSystemErr.println("Could not open " + reportFile + " for writing. Will write the unit test report to the console instead.");
e.printStackTrace(originalSystemErr);
reportStream = originalSystemErr;
}
reportStream.println(center("UNIT TEST REPORT"));
reportStream.println(center("----------------") + EOL);
reportStream.println("Finished at: " + new Date());
reportStream.println("# Test classes: " + _classResults.size());
reportStream.println("# Test classes interleaved: " + _classesWithTestsRunInterleaved.size());
reportStream.println("# Test methods: " + countTestMethods());
reportStream.println("# Tests passed: " + countTestsWithStatus(ITestResult.SUCCESS));
reportStream.println("# Tests failed: " + countTestsWithStatus(ITestResult.FAILURE));
reportStream.println(EOL + DIVIDER_LINE + DIVIDER_LINE + EOL + EOL);
reportStream.println(center("TEST CLASSES RUN INTERLEAVED"));
reportStream.println(EOL + EOL);
for (Class<?> cls : _classesWithTestsRunInterleaved)
{
reportStream.println(" " + cls.getName());
}
reportStream.println(EOL + DIVIDER_LINE + DIVIDER_LINE + EOL + EOL);
reportStream.println(center("FAILED TESTS"));
reportStream.println(EOL + EOL);
reportStream.println(_bufferedTestFailures);
reportStream.println(EOL + DIVIDER_LINE + DIVIDER_LINE + EOL);
reportStream.println(getTimingInfo());
reportStream.close();
if (countTestsWithStatus(ITestResult.FAILURE) == 0
&& countTestsWithStatus(ITestResult.SKIP) != 0) {
originalSystemErr.println("There were no explicit test failures, but some tests were skipped (possibly due to errors in @Before* or @After* methods).");
System.exit(-1);
}
}
private String getFqMethod(ITestResult result) {
IClass cls = result.getTestClass();
ITestNGMethod method = result.getMethod();
return cls.getName() + "#" + method.getMethodName();
}
private void writeReportToScreen(File reportFile) {
// HACK: print out status for the last test object
outputTestProgress(_lastTestObject);
List<ITestResult> failedTests = getFailedTests();
StringBuilder failed = new StringBuilder();
for (int i = 0; i < failedTests.size(); i++) {
ITestResult failedTest = failedTests.get(i);
String fqMethod = getFqMethod(failedTest);
int numFailures = 1;
// Peek ahead to see if we had multiple failures for the same method
// In which case, we list it once with a count of the failures.
while (i + 1 < failedTests.size()
&& fqMethod.equals(getFqMethod(failedTests.get(i+1)))) {
numFailures++;
i++;
}
failed.append(" ").append(fqMethod);
if (numFailures > 1) {
failed.append(" (x ").append(numFailures).append(")");
}
failed.append(EOL);
}
if (failed.length() > 0) {
originalSystemErr.println("The following unit tests failed: ");
originalSystemErr.println(failed);
originalSystemErr.println();
originalSystemErr.println("Include the ant option '-Dtest.failures=true' to rerun only the failed tests.");
} else {
originalSystemErr.println("All of the tests passed.");
}
originalSystemErr.println();
originalSystemErr.println("Wrote full test report to:");
originalSystemErr.println(reportFile.getAbsolutePath());
originalSystemErr.println("Test classes run interleaved: " + _classesWithTestsRunInterleaved.size());
// Try to hard to reclaim as much memory as possible.
runGc();
originalSystemErr.printf("Final amount of memory in use: %.1f MB",
(usedMemory() / (1024.0 * 1024.0))).println();
if (doProgressMemory) {
originalSystemErr.printf("Maximum amount of memory in use: %.1f MB",
(maxMemInUse / (1024.0 * 1024.0))).println();
}
originalSystemErr.println("Final number of threads: " + Thread.activeCount());
List<Long> systemRestartTimes = TestCaseUtils.getRestartTimesMs();
long totalRestartMs = 0;
for (long restartMs: systemRestartTimes) {
totalRestartMs += restartMs;
}
double averageRestartSec = 0;
if (!systemRestartTimes.isEmpty()) {
averageRestartSec = totalRestartMs / (1000.0 * systemRestartTimes.size());
}
originalSystemErr.printf("In core restarts: %d (took %.1fs on average)",
TestCaseUtils.getNumServerRestarts(), averageRestartSec);
originalSystemErr.println();
if (!_classesWithTestsRunInterleaved.isEmpty()) {
System.err.println("WARNING: Some of the test methods for multiple classes " +
"were run out of order (i.e. interleaved with other classes). Either " +
"a class doesn't have the sequential=true annotation, which should " +
"have been reported already or there has been a regression with TestNG.");
}
}
@Override
public void onTestStart(ITestResult tr) {
super.onTestStart(tr);
enforceTestClassTypeAndAnnotations(tr);
checkForInterleavedBetweenClasses(tr);
enforceMethodHasAnnotation(tr);
}
private void onTestFinished(ITestResult tr) {
// Clear when a test finishes instead before the next one starts
// so that we get the output generated by any @BeforeClass method etc.
TestCaseUtils.clearLoggersContents();
addTestResult(tr);
}
@Override
public void onTestSuccess(ITestResult tr) {
super.onTestSuccess(tr);
onTestFinished(tr);
}
@Override
public void onTestFailure(ITestResult tr) {
super.onTestFailure(tr);
reportTestFailed(tr);
}
private void reportTestFailed(ITestResult tr)
{
IClass cls = tr.getTestClass();
ITestNGMethod method = tr.getMethod();
String fqMethod = cls.getName() + "#" + method.getMethodName();
StringBuilder failureInfo = new StringBuilder();
failureInfo.append("Failed Test: ").append(fqMethod).append(EOL);
Object[] parameters = tr.getParameters();
Throwable cause = tr.getThrowable();
if (cause != null) {
failureInfo.append("Failure Cause: ").append(getTestngLessStack(cause));
}
for (int i = 0; parameters != null && i < parameters.length; i++) {
Object parameter = parameters[i];
failureInfo.append("parameter[").append(i).append("]: ")
.append(parameter).append(EOL);
}
appendFailureInfo(failureInfo);
failureInfo.append(EOL).append(EOL);
originalSystemErr.print(EOL + EOL + EOL + " T E S T S K I P P E D ! ! !" + EOL + EOL);
originalSystemErr.print(failureInfo);
originalSystemErr.print(DIVIDER_LINE + EOL + EOL);
_bufferedTestFailures.append(failureInfo);
String pauseStr = System.getProperty("org.opends.test.pauseOnFailure");
if ("true".equalsIgnoreCase(pauseStr))
{
pauseOnFailure();
}
onTestFinished(tr);
}
public static void pauseOnFailure() {
File tempFile = null;
try
{
tempFile = File.createTempFile("testfailure", "watchdog");
tempFile.deleteOnExit();
originalSystemErr.println("**** Pausing test execution until file " +
tempFile.getCanonicalPath() + " is removed.");
originalSystemErr.println("LDAP Port: " +
TestCaseUtils.getServerLdapPort());
originalSystemErr.println("LDAPS Port: " +
TestCaseUtils.getServerLdapsPort());
originalSystemErr.println("JMX Port: " +
TestCaseUtils.getServerJmxPort());
}
catch (Exception e)
{
originalSystemErr.println("**** ERROR: Could not create a watchdog " +
"file. Pausing test execution indefinitely.");
originalSystemErr.println("**** You will have to manually kill the " +
"JVM when you're done investigating the problem.");
}
while (tempFile != null && tempFile.exists())
{
try
{
Thread.sleep(100);
} catch (Exception e) {}
}
originalSystemErr.println("**** Watchdog file removed. Resuming test " +
"case execution.");
}
private void appendFailureInfo(StringBuilder failureInfo)
{
TestCaseUtils.appendLogsContents(failureInfo);
}
@Override
public void onConfigurationSkip(ITestResult tr) {
super.onConfigurationFailure(tr);
reportConfigurationFailure(tr);
}
private void reportConfigurationFailure(ITestResult tr)
{
IClass cls = tr.getTestClass();
ITestNGMethod method = tr.getMethod();
String fqMethod = cls.getName() + "#" + method.getMethodName();
StringBuilder failureInfo = new StringBuilder();
failureInfo.append("Failed Test: ").append(fqMethod).append(EOL);
Throwable cause = tr.getThrowable();
if (cause != null) {
failureInfo.append("Failure Cause: ").append(getTestngLessStack(cause));
}
appendFailureInfo(failureInfo);
failureInfo.append(EOL).append(EOL);
originalSystemErr.print(EOL + EOL + EOL + " C O N F I G U R A T I O N S K I P ! ! !" + EOL + EOL);
originalSystemErr.print(failureInfo);
originalSystemErr.print(DIVIDER_LINE + EOL + EOL);
_bufferedTestFailures.append(failureInfo);
}
@Override
public void onConfigurationFailure(ITestResult tr) {
super.onConfigurationFailure(tr);
reportConfigurationFailure(tr);
}
private String getTestngLessStack(Throwable t) {
StackTraceElement[] elements = t.getStackTrace();
int lowestOpenDSFrame;
for (lowestOpenDSFrame = elements.length - 1; lowestOpenDSFrame >= 0; lowestOpenDSFrame--) {
StackTraceElement element = elements[lowestOpenDSFrame];
String clsName = element.getClassName();
if (clsName.startsWith("org.opends.") && !"org.opends.server.SuiteRunner".equals(clsName)) {
break;
}
}
StringBuilder buffer = new StringBuilder();
buffer.append(t).append(EOL);
for (int i = 0; i <= lowestOpenDSFrame; i++) {
buffer.append(" ").append(elements[i]).append(EOL);
}
Throwable cause = t.getCause();
if (cause instanceof InvocationTargetException) {
InvocationTargetException invocation = (InvocationTargetException) cause;
buffer.append("Invocation Target Exception: ").append(
getTestngLessStack(invocation));
}
t.printStackTrace();
return buffer.toString();
}
private static final int PAGE_WIDTH = 80;
private static String center(String header) {
StringBuilder buffer = new StringBuilder();
int indent = (PAGE_WIDTH - header.length()) / 2;
for (int i = 0; i < indent; i++) {
buffer.append(" ");
}
buffer.append(header);
return buffer.toString();
}
@Override
public void onTestSkipped(ITestResult tr) {
// Make sure skipped test appear as failure
super.onTestFailure(tr);
reportTestFailed(tr);
}
@Override
public void onTestFailedButWithinSuccessPercentage(ITestResult tr) {
super.onTestFailedButWithinSuccessPercentage(tr);
onTestFinished(tr);
}
private void addTestResult(ITestResult result) {
getResultsForClass(result.getTestClass()).addTestResult(result);
// Read the comments in DirectoryServerTestCase to understand what's
// going on here.
Object[] testInstances = result.getMethod().getInstances();
for (Object testInstance : testInstances)
{
if (testInstance instanceof DirectoryServerTestCase) {
DirectoryServerTestCase dsTestCase = (DirectoryServerTestCase)testInstance;
Object[] parameters = result.getParameters();
if (result.getStatus() == ITestResult.SUCCESS) {
dsTestCase.addParamsFromSuccessfulTests(parameters);
// This can eat up a bunch of memory for tests that are expected to throw
result.setThrowable(null);
} else {
dsTestCase.addParamsFromFailedTest(parameters);
// When the test finishes later on, we might not have everything
// that we need to print the result (e.g. the Schema for an Entry
// or DN), so go ahead and convert it to a String now.
result.setParameters(convertToStringParameters(parameters));
}
} // else we already warned about it.
}
}
private String[] convertToStringParameters(Object[] parameters) {
if (parameters == null) {
return null;
}
String[] strParams = new String[parameters.length];
for (int i = 0; i < parameters.length; i++) {
strParams[i] = String.valueOf(parameters[i]).intern();
}
return strParams;
}
private Set<Class<?>> _checkedForTypeAndAnnotations = new HashSet<>();
private void enforceTestClassTypeAndAnnotations(ITestResult tr) {
Class<?> testClass = tr.getMethod().getRealClass();
// Only warn once per class.
if (_checkedForTypeAndAnnotations.contains(testClass)) {
return;
}
_checkedForTypeAndAnnotations.add(testClass);
if (!DirectoryServerTestCase.class.isAssignableFrom(testClass)) {
String errorMessage =
"The test class " + testClass.getName() + " must inherit (directly or indirectly) " +
"from DirectoryServerTestCase.";
TestCaseUtils.originalSystemErr.println("\n\nERROR: " + errorMessage + "\n\n");
throw new RuntimeException(errorMessage);
}
Class<?> classWithTestAnnotation = findClassWithTestAnnotation(testClass);
if (classWithTestAnnotation == null) {
String errorMessage =
"The test class " + testClass.getName() + " does not have a @Test annotation. " +
"All test classes must have a @Test annotation, and this annotation must have " +
"sequential=true set to ensure that tests for a single class are run together.";
TestCaseUtils.originalSystemErr.println("\n\nERROR: " + errorMessage + "\n\n");
throw new RuntimeException(errorMessage);
}
Test testAnnotation = classWithTestAnnotation.getAnnotation(Test.class);
if (!testAnnotation.sequential()) {
// Give an error message that is as specific as possible.
String errorMessage =
"The @Test annotation for class " + testClass.getName() +
(classWithTestAnnotation.equals(testClass) ? " " : (", which is declared by class " + classWithTestAnnotation.getName() + ", ")) +
"must include sequential=true to ensure that tests for a single class are run together.";
TestCaseUtils.originalSystemErr.println("\n\nERROR: " + errorMessage + "\n\n");
throw new RuntimeException(errorMessage);
}
}
private final LinkedHashSet<Class<?>> _classesWithTestsRunInterleaved = new LinkedHashSet<>();
private Object _lastTestObject;
private final IdentityHashMap<Object,Object> _previousTestObjects = new IdentityHashMap<>();
private void checkForInterleavedBetweenClasses(ITestResult tr) {
Object[] testInstances = tr.getMethod().getInstances();
// This will almost always have a single element. If it doesn't, just skip it.
if (testInstances.length != 1) {
return;
}
Object testInstance = testInstances[0];
// We're running another test on the same test object. Everything is fine.
if (_lastTestObject == testInstance) {
return;
}
// Otherwise, we're running a new test, so save the old one.
if (_lastTestObject != null) {
_previousTestObjects.put(_lastTestObject, _lastTestObject);
}
// Output progress info since we're running a new class
outputTestProgress(_lastTestObject);
// And make sure we don't have a test object that we already ran tests with.
if (_previousTestObjects.containsKey(testInstance)) {
_classesWithTestsRunInterleaved.add(testInstance.getClass());
}
_lastTestObject = testInstance;
}
private Set<Method> _checkedForAnnotation = new HashSet<>();
private void enforceMethodHasAnnotation(ITestResult tr) {
// Only warn once per method.
Method testMethod = tr.getMethod().getMethod();
if (_checkedForAnnotation.contains(testMethod)) {
return;
}
_checkedForAnnotation.add(testMethod);
Annotation testAnnotation = testMethod.getAnnotation(Test.class);
Annotation dataProviderAnnotation = testMethod.getAnnotation(DataProvider.class);
if (testAnnotation == null && dataProviderAnnotation == null) {
String errorMessage =
"The test method " + testMethod + " does not have a @Test annotation. " +
"However, TestNG assumes it is a test method because it's a public method " +
"in a class with a class-level @Test annotation. You can remove this warning by either " +
"marking the method with @Test or by making it non-public.";
TestCaseUtils.originalSystemErr.println("\n\nWARNING: " + errorMessage + "\n\n");
}
}
/**
* Return the class in cls's inheritance hierarchy that has the @Test
* annotation defined.
*/
private Class<?> findClassWithTestAnnotation(Class<?> cls) {
while (cls != null) {
if (cls.getAnnotation(Test.class) != null) {
return cls;
}
cls = cls.getSuperclass();
}
return null;
}
private boolean statusHeaderPrinted;
private synchronized void printStatusHeaderOnce() {
if (statusHeaderPrinted) {
return;
}
statusHeaderPrinted = true;
if (doProgressNone) {
return;
}
originalSystemErr.println();
originalSystemErr.println("How to read the progressive status info:");
if (doProgressTime) {
originalSystemErr.println(" Test duration status: {Total min:sec. Since last status sec.}");
}
if (doProgressTestCount) {
originalSystemErr.println(" Test count status: {# test classes # test methods # test method invocations # test failures}.");
}
if (doProgressMemory) {
originalSystemErr.println(" Memory usage status: {MB in use +/-change since last status}");
}
if (doProgressMemoryGcs) {
originalSystemErr.println(" GCs during status: {GCs done to settle used memory time to do it}");
}
if (doProgressThreadCount) {
originalSystemErr.println(" Thread count status: {#td number of active threads}");
}
if (doProgressRestarts) {
originalSystemErr.println(" In core restart status: {#rs number of in-core restarts}");
}
if (doProgressThreadChange) {
originalSystemErr.println(" Thread change status: +/- thread name for new or finished threads since last status");
}
originalSystemErr.println(" TestClass (the class that just completed)");
originalSystemErr.println();
}
private final long testSuiteStartTime = System.currentTimeMillis();
private long prevMemInUse;
private long maxMemInUse;
private boolean isFirstTest = true;
private void outputTestProgress(Object finishedTestObject)
{
if (doProgressNone)
{
return;
}
printStatusHeaderOnce();
DirectoryServerTestCase testInstance = (DirectoryServerTestCase) finishedTestObject;
long startTime = testInstance != null ? testInstance.startTime : testSuiteStartTime;
originalSystemErr.printf("[%s] ",
TEST_PROGESS_TIME_FORMAT.format(new Date(startTime)));
if (doProgressTime)
{
long endTime = testInstance != null ? testInstance.endTime : System
.currentTimeMillis();
long durationSec = (endTime - testSuiteStartTime) / 1000;
long durationLastMs = endTime - startTime;
originalSystemErr.printf("{%2d:%02d (%3.0fs)} ", (durationSec / 60),
(durationSec % 60), (durationLastMs / 1000.0));
}
if (doProgressTestCount) {
originalSystemErr.printf("{%3dc %4dm %5di %df} ",
_classResults.size(), countTestMethods(), countTotalInvocations(),
countTestsWithStatus(ITestResult.FAILURE));
}
if (doProgressMemory) {
Runtime runtime = Runtime.getRuntime();
TestCaseUtils.quiesceServer();
long beforeGc = System.currentTimeMillis();
int gcs = runGc();
long gcDuration = System.currentTimeMillis() - beforeGc;
long totalMemory = runtime.totalMemory();
long freeMemory = runtime.freeMemory();
long curMemInUse = totalMemory - freeMemory;
long memDelta = curMemInUse - prevMemInUse;
double perMegaByte = 1.0 / (1024.0 * 1024.0);
maxMemInUse = Math.max(maxMemInUse, curMemInUse);
originalSystemErr.printf("{%5.1fMB %+5.1fMB} ",
curMemInUse * perMegaByte,
memDelta * perMegaByte);
if (doProgressMemoryGcs) {
originalSystemErr.printf("{%2d gcs %4.1fs} ",
gcs,
gcDuration / 1000.0);
}
prevMemInUse = curMemInUse;
}
if (doProgressThreadCount) {
originalSystemErr.printf("{#td %3d} ", Thread.activeCount());
}
if (doProgressRestarts) {
originalSystemErr.printf("{#rs %2d} ", TestCaseUtils.getNumServerRestarts());
}
if (testInstance == null) {
originalSystemErr.println(": starting");
} else {
String abbrClass = packageLessClass(testInstance);
originalSystemErr.printf(": %s ", abbrClass).flush();
originalSystemErr.println();
if (doProgressThreadChange)
{
if (isFirstTest)
{
isFirstTest = false;
}
else
{
List<String> startThreads = testInstance.threadNamesBeforeClass;
List<String> endThreads = testInstance.threadNamesAfterClass;
List<String> removedThreads = removeExactly(startThreads, endThreads);
List<String> addedThreads = removeExactly(endThreads, startThreads);
if (!removedThreads.isEmpty() || !addedThreads.isEmpty())
{
originalSystemErr.println(" Thread changes:");
for (String threadName : addedThreads)
{
originalSystemErr.println(" + " + threadName);
}
for (String threadName : removedThreads)
{
originalSystemErr.println(" - " + threadName);
}
}
}
}
}
}
private int runGc() {
Runtime runtime = Runtime.getRuntime();
int numGcs;
long curMem = usedMemory();
long prevMem = Long.MAX_VALUE;
StringBuilder gcConvergence = new StringBuilder();
for (numGcs = 0; prevMem > curMem && numGcs < 100; numGcs++) {
runtime.runFinalization();
runtime.gc();
Thread.yield();
Thread.yield();
prevMem = curMem;
curMem = usedMemory();
gcConvergence.append("[").append(numGcs).append("]: ").append(
prevMem - curMem).append(" ");
}
return numGcs;
}
/**
* Removes toRemove from base. If there are duplicate items in base, then
* only one is removed for each item in toRemove.
*
* @return a new List with base with toRemove items removed from it
*/
private List<String> removeExactly(List<String> base, List<String> toRemove) {
List<String> diff = new ArrayList<>(base);
diff.removeAll(toRemove);
return diff;
}
private String packageLessClass(Object obj) {
return obj.getClass().getName().replaceAll(".*\\.", "");
}
private long usedMemory() {
Runtime runtime = Runtime.getRuntime();
return runtime.totalMemory() - runtime.freeMemory();
}
private final LinkedHashMap<IClass, TestClassResults> _classResults = new LinkedHashMap<>();
private TestClassResults getResultsForClass(IClass cls) {
TestClassResults results = _classResults.get(cls);
if (results == null) {
results = new TestClassResults(cls);
_classResults.put(cls, results);
}
return results;
}
synchronized StringBuilder getTimingInfo() {
StringBuilder timingOutput = new StringBuilder();
timingOutput.append(center("TESTS RUN BY CLASS")).append(EOL);
timingOutput.append(center("[method-name total-time (total-invocations)]"))
.append(EOL).append(EOL);
for (TestClassResults results: _classResults.values()) {
results.getTimingInfo(timingOutput);
}
timingOutput.append(EOL).append(DIVIDER_LINE).append(DIVIDER_LINE).append(EOL);
getSlowestTestsOutput(timingOutput);
return timingOutput;
}
private int countTestMethods() {
int count = 0;
for (TestClassResults results: _classResults.values()) {
count += results._methods.size();
}
return count;
}
private int countTestsWithStatus(int status) {
int count = 0;
for (TestClassResults results: _classResults.values()) {
count += results._resultCounts[status];
}
return count;
}
private int countTotalInvocations() {
int count = 0;
for (TestClassResults results: _classResults.values()) {
count += results._totalInvocations;
}
return count;
}
private synchronized List<TestMethodResults> getAllMethodResults() {
List<TestMethodResults> allResults = new ArrayList<>();
for (TestClassResults results: _classResults.values()) {
allResults.addAll(results.getAllMethodResults());
}
return allResults;
}
private static final int NUM_SLOWEST_METHODS = 100;
private void getSlowestTestsOutput(StringBuilder timingOutput) {
timingOutput.append(center("CLASS SUMMARY SORTED BY DURATION")).append(EOL);
timingOutput.append(center("[class-name total-time (total-invocations)]"))
.append(EOL).append(EOL);
List<TestClassResults> sortedClasses = getClassesDescendingSortedByDuration();
for (int i = 0; i < sortedClasses.size(); i++) {
TestClassResults results = sortedClasses.get(i);
timingOutput.append(" ");
results.getSummaryTimingInfo(timingOutput);
timingOutput.append(EOL);
}
timingOutput.append(EOL).append(DIVIDER_LINE).append(EOL).append(EOL);
timingOutput.append(center("SLOWEST METHODS")).append(EOL);
timingOutput.append(center("[method-name total-time (total-invocations)]"))
.append(EOL).append(EOL);
List<TestMethodResults> sortedMethods = getMethodsDescendingSortedByDuration();
for (int i = 0; i < Math.min(sortedMethods.size(), NUM_SLOWEST_METHODS); i++) {
TestMethodResults results = sortedMethods.get(i);
results.getTimingInfo(timingOutput, true);
}
}
private List<TestMethodResults> getMethodsDescendingSortedByDuration() {
List<TestMethodResults> allMethods = getAllMethodResults();
Collections.sort(allMethods, new Comparator<TestMethodResults>() {
@Override
public int compare(TestMethodResults o1, TestMethodResults o2) {
if (o1._totalDurationMs > o2._totalDurationMs) {
return -1;
} else if (o1._totalDurationMs < o2._totalDurationMs) {
return 1;
} else {
return 0;
}
}
});
return allMethods;
}
private List<TestClassResults> getClassesDescendingSortedByDuration() {
List<TestClassResults> allClasses = new ArrayList<>(_classResults.values());
Collections.sort(allClasses, new Comparator<TestClassResults>() {
@Override
public int compare(TestClassResults o1, TestClassResults o2) {
if (o1._totalDurationMs > o2._totalDurationMs) {
return -1;
} else if (o1._totalDurationMs < o2._totalDurationMs) {
return 1;
} else {
return 0;
}
}
});
return allClasses;
}
private static final String[] STATUSES =
{"<<invalid>>", "Success", "Failure", "Skip", "Success Percentage Failure"};
private static class TestClassResults {
private final IClass _cls;
private final LinkedHashMap<ITestNGMethod, TestMethodResults> _methods = new LinkedHashMap<>();
private int _totalInvocations;
private long _totalDurationMs;
/** Indexed by SUCCESS, FAILURE, SKIP, SUCCESS_PERCENTAGE_FAILURE. */
private int[] _resultCounts = new int[STATUSES.length];
public TestClassResults(IClass cls) {
_cls = cls;
}
synchronized void addTestResult(ITestResult result) {
_totalInvocations++;
_totalDurationMs += result.getEndMillis() - result.getStartMillis();
getResultsForMethod(result.getMethod()).addTestResult(result);
int status = result.getStatus();
if (status < 0 || status >= _resultCounts.length) {
status = 0;
}
_resultCounts[status]++;
}
private TestMethodResults getResultsForMethod(ITestNGMethod method) {
TestMethodResults results = _methods.get(method);
if (results == null) {
results = new TestMethodResults(method);
_methods.put(method, results);
}
return results;
}
synchronized void getSummaryTimingInfo(StringBuilder timingOutput) {
timingOutput.append(_cls.getRealClass().getName()).append(" ");
timingOutput.append(getTotalDurationMs()).append(" ms")
.append(" (").append(getTotalInvocations()).append(")");
}
synchronized Collection<TestMethodResults> getAllMethodResults() {
return _methods.values();
}
synchronized void getTimingInfo(StringBuilder timingOutput) {
getSummaryTimingInfo(timingOutput);
timingOutput.append(EOL);
for (TestMethodResults results: getAllMethodResults()) {
results.getTimingInfo(timingOutput, false);
}
timingOutput.append(EOL);
}
int getTotalInvocations() {
return _totalInvocations;
}
long getTotalDurationMs() {
return _totalDurationMs;
}
}
private static class TestMethodResults {
private final ITestNGMethod _method;
int _totalInvocations;
long _totalDurationMs;
/** Indexed by SUCCESS, FAILURE, SKIP, SUCCESS_PERCENTAGE_FAILURE. */
private int[] _resultCounts = new int[STATUSES.length];
public TestMethodResults(ITestNGMethod method) {
_method = method;
}
synchronized void addTestResult(ITestResult result) {
_totalInvocations++;
_totalDurationMs += result.getEndMillis() - result.getStartMillis();
int status = result.getStatus();
if (status < 0 || status >= _resultCounts.length) {
status = 0;
}
_resultCounts[status]++;
}
synchronized void getTimingInfo(StringBuilder timingOutput, boolean includeClassName) {
timingOutput.append(" ");
if (includeClassName) {
timingOutput.append(_method.getRealClass().getName()).append("#");
}
timingOutput.append(_method.getMethodName()).append(" ");
timingOutput.append(_totalDurationMs).append(" ms")
.append(" (").append(_totalInvocations).append(")");
if (_resultCounts[ITestResult.FAILURE] > 0) {
timingOutput.append(" ").append(_resultCounts[ITestResult.FAILURE])
.append(" failure(s)");
}
timingOutput.append(EOL);
}
}
}