From 4f08004850d8a1ca45517e7cd3297719eaa550b5 Mon Sep 17 00:00:00 2001
From: Matthew Swift <matthew.swift@forgerock.com>
Date: Fri, 06 Dec 2013 13:29:54 +0000
Subject: [PATCH] * print time stamps for each unit test status in order to help correlate tests against logs * improve code for tracking thread count changes.

---
 opends/tests/unit-tests-testng/src/server/org/opends/server/TestListener.java |   88 +++++++++++++++++++++++++-------------------
 1 files changed, 50 insertions(+), 38 deletions(-)

diff --git a/opends/tests/unit-tests-testng/src/server/org/opends/server/TestListener.java b/opends/tests/unit-tests-testng/src/server/org/opends/server/TestListener.java
index 72ea5db..da9b9c7 100644
--- a/opends/tests/unit-tests-testng/src/server/org/opends/server/TestListener.java
+++ b/opends/tests/unit-tests-testng/src/server/org/opends/server/TestListener.java
@@ -36,9 +36,11 @@
 import org.testng.annotations.Test;
 import org.testng.annotations.DataProvider;
 import org.testng.xml.XmlSuite;
+
 import static org.opends.server.util.ServerConstants.EOL;
 import static org.opends.server.TestCaseUtils.originalSystemErr;
 
+import java.text.SimpleDateFormat;
 import java.util.List;
 import java.util.LinkedHashMap;
 import java.util.Collection;
@@ -66,27 +68,30 @@
  */
 public class TestListener extends TestListenerAdapter implements IReporter {
 
-  public static final String REPORT_FILE_NAME = "results.txt";
+  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.
-  public static final String ANT_TESTS_FAILED_FILE_NAME = ".tests-failed-marker";
+  private static final String ANT_TESTS_FAILED_FILE_NAME = ".tests-failed-marker";
 
 
   private final StringBuilder _bufferedTestFailures = new StringBuilder();
 
 
-  public static final String PROPERTY_TEST_PROGRESS = "test.progress";
-  public static final String TEST_PROGRESS_NONE = "none";
-  public static final String TEST_PROGRESS_ALL = "all";
-  public static final String TEST_PROGRESS_DEFAULT = "default";
-  public static final String TEST_PROGRESS_TIME = "time";
-  public static final String TEST_PROGRESS_TEST_COUNT = "count";
-  public static final String TEST_PROGRESS_MEMORY = "memory";
-  public static final String TEST_PROGRESS_MEMORY_GCS = "gcs";  // Hidden for now, since it's not useful to most developers
-  public static final String TEST_PROGRESS_RESTARTS = "restarts";
-  public static final String TEST_PROGRESS_THREAD_COUNT = "threadcount";
-  public static final String TEST_PROGRESS_THREAD_CHANGES = "threadchanges";
+  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";
+  private static final String TEST_PROGRESS_MEMORY_GCS = "gcs";  // Hidden for now, since it's not useful to most developers
+  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 = false;
   private boolean doProgressTime = true;
@@ -95,7 +100,7 @@
   private boolean doProgressMemoryGcs = false;
   private boolean doProgressRestarts = true;
   private boolean doProgressThreadCount = false;
-  private boolean doProgressThreadChanges = false;
+  private boolean doProgressThreadChange = false;
 
   private void initializeProgressVars() {
     String prop = System.getProperty(PROPERTY_TEST_PROGRESS);
@@ -116,7 +121,7 @@
       doProgressMemoryGcs = false;
       doProgressRestarts = false;
       doProgressThreadCount = false;
-      doProgressThreadChanges = false;
+      doProgressThreadChange = false;
     } else if (progressValues.contains(TEST_PROGRESS_ALL)) {
       doProgressNone = false;
       doProgressTime = true;
@@ -125,7 +130,7 @@
       doProgressMemoryGcs = true;
       doProgressRestarts = true;
       doProgressThreadCount = true;
-      doProgressThreadChanges = true;
+      doProgressThreadChange = true;
     } else {
       doProgressNone = false;
       doProgressTime = progressValues.contains(TEST_PROGRESS_TIME);
@@ -134,7 +139,7 @@
       doProgressMemoryGcs = progressValues.contains(TEST_PROGRESS_MEMORY_GCS);
       doProgressRestarts = progressValues.contains(TEST_PROGRESS_RESTARTS);
       doProgressThreadCount = progressValues.contains(TEST_PROGRESS_THREAD_COUNT);
-      doProgressThreadChanges = progressValues.contains(TEST_PROGRESS_THREAD_CHANGES);
+      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)) {
@@ -231,7 +236,7 @@
 
   private void writeReportToScreen(File reportFile) {
     // HACK: print out status for the last test object
-    outputTestProgress(_lastTestObject);
+    outputTestProgress(_lastTestObject, true);
 
     List<ITestResult> failedTests = getFailedTests();
     StringBuilder failed = new StringBuilder();
@@ -295,9 +300,9 @@
             TestCaseUtils.getNumServerRestarts(), averageRestartSec);
     originalSystemErr.println();
 
-    if (doProgressThreadChanges) {
-      originalSystemErr.print(TestCaseUtils.threadStacksToString());      
-    }
+//    if (doProgressThreadChange) {
+//      originalSystemErr.print(TestCaseUtils.threadStacksToString());
+//    }
 
     if (_classesWithTestsRunInterleaved.size() > 0) {
       System.err.println("WARNING:  Some of the test methods for multiple classes " +
@@ -421,8 +426,6 @@
 
     StringBuilder failureInfo = new StringBuilder();
     failureInfo.append("Failed Test:  ").append(fqMethod).append(EOL);
-    Object[] parameters = tr.getParameters();
-
 
     Throwable cause = tr.getThrowable();
     if (cause != null) {
@@ -603,8 +606,8 @@
     }
 
     // Output progress info since we're running a new class
-    outputTestProgress(_lastTestObject);
-    
+    outputTestProgress(_lastTestObject, false);
+
     // And make sure we don't have a test object that we already ran tests with.
     if (_previousTestObjects.containsKey(testInstance)) {
       _classesWithTestsRunInterleaved.add(testInstance.getClass());
@@ -690,7 +693,7 @@
       originalSystemErr.println("  In core restart status: {#rs number of in-core restarts}");
     }
 
-    if (doProgressThreadChanges) {
+    if (doProgressThreadChange) {
       originalSystemErr.println("  Thread change status: +/- thread name for new or finished threads since last status");
     }
 
@@ -703,13 +706,21 @@
   private List<String> prevThreads = new ArrayList<String>();
   private long prevMemInUse = 0;
   private long maxMemInUse = 0;
-  private void outputTestProgress(Object finishedTestObject) {
-    if (doProgressNone) {
+
+
+
+  private void outputTestProgress(Object finishedTestObject, boolean isLastTest)
+  {
+    if (doProgressNone)
+    {
       return;
     }
 
     printStatusHeaderOnce();
 
+    String timeStamp = TEST_PROGESS_TIME_FORMAT.format(new Date());
+    originalSystemErr.printf("[%s]  ", timeStamp);
+
     if (doProgressTime) {
       long curTimeMs = System.currentTimeMillis();
       long durationSec = (curTimeMs - startTimeMs) / 1000;
@@ -770,19 +781,21 @@
       originalSystemErr.println();
     }
 
-    if (doProgressThreadChanges) {
+    if (doProgressThreadChange) {
+      boolean isFirstOrLastTest = prevThreads.isEmpty() || isLastTest;
       List<String> currentThreads = listAllThreadNames();
-      List<String> newThreads = removeExactly(prevThreads, currentThreads);
-      List<String> oldThreads = removeExactly(currentThreads, prevThreads);
+      List<String> removedThreads = removeExactly(prevThreads, currentThreads);
+      List<String> addedThreads = removeExactly(currentThreads, prevThreads);
 
-      if (!newThreads.isEmpty()) {
+      if (!isFirstOrLastTest
+          && (!removedThreads.isEmpty() || !addedThreads.isEmpty()))
+      {
         originalSystemErr.println("  Thread changes:");
-        for (int i = 0; i < oldThreads.size(); i++) {
-          String threadName =  oldThreads.get(i);
+        for (String threadName : addedThreads)
+        {
           originalSystemErr.println("    + " + threadName);
         }
-        for (int i = 0; i < newThreads.size(); i++) {
-          String threadName =  newThreads.get(i);
+        for (String threadName : removedThreads) {
           originalSystemErr.println("    - " + threadName);
         }
       }
@@ -843,8 +856,7 @@
    */
   private List<String> removeExactly(List<String> base, List<String> toRemove) {
     List<String> diff = new ArrayList<String>(base);
-    for (int i = 0; i < toRemove.size(); i++) {
-      String item = toRemove.get(i);
+    for (String item : toRemove) {
       diff.remove(item);
     }
     return diff;

--
Gitblit v1.10.0