Added tracking of test run duration.

Change-Id: Ideeb01b8d822a90433aad4b90ebb6fb479759a1a

@@ -109,6 +109,15 @@ public class Coordinator {
     }
     }
 
 
     /**
     /**
+     * Returns number of milliseconds it took to execute.
+     *
+     * @return number of millis elapsed during the run
+     */
+    public long duration() {
+        return store.endTime() - store.startTime();
+    }
+
+    /**
      * Returns a list of steps that match the specified list of patterns.
      * Returns a list of steps that match the specified list of patterns.
      *
      *
      * @param runToPatterns list of patterns
      * @param runToPatterns list of patterns

@@ -44,11 +44,12 @@ public final class Main {
     private static final String GREEN = "\u001B[32;1m";
     private static final String GREEN = "\u001B[32;1m";
     private static final String BLUE = "\u001B[36m";
     private static final String BLUE = "\u001B[36m";
 
 
-    private static final String SUCCESS_SUMMARY = "%sPassed! %d steps succeeded%s";
+    private static final String SUCCESS_SUMMARY =
+            "%s %sPassed! %d steps succeeded%s";
     private static final String MIXED_SUMMARY =
     private static final String MIXED_SUMMARY =
             "%s%d steps succeeded; %s%d steps failed; %s%d steps skipped%s";
             "%s%d steps succeeded; %s%d steps failed; %s%d steps skipped%s";
-    private static final String FAILURE_SUMMARY = "%sFailed! " + MIXED_SUMMARY;
-    private static final String ABORTED_SUMMARY = "%sAborted! " + MIXED_SUMMARY;
+    private static final String FAILURE_SUMMARY = "%s %sFailed! " + MIXED_SUMMARY;
+    private static final String ABORTED_SUMMARY = "%s %sAborted! " + MIXED_SUMMARY;
 
 
     private boolean isReported = false;
     private boolean isReported = false;
 
 
@@ -180,6 +181,7 @@ public final class Main {
     private void processList() {
     private void processList() {
         coordinator.getRecords()
         coordinator.getRecords()
                 .forEach(event -> logStatus(event.time(), event.name(), event.status(), event.command()));
                 .forEach(event -> logStatus(event.time(), event.name(), event.status(), event.command()));
+        printSummary(0, false);
         System.exit(0);
         System.exit(0);
     }
     }
 
 
@@ -201,14 +203,15 @@ public final class Main {
         if (!isReported) {
         if (!isReported) {
             isReported = true;
             isReported = true;
             Set<Step> steps = coordinator.getSteps();
             Set<Step> steps = coordinator.getSteps();
+            String duration = formatDuration((int) (coordinator.duration() / 1_000));
             int count = steps.size();
             int count = steps.size();
             if (exitCode == 0) {
             if (exitCode == 0) {
-                print(SUCCESS_SUMMARY, color(SUCCEEDED), count, color(null));
+                print(SUCCESS_SUMMARY, duration, color(SUCCEEDED), count, color(null));
             } else {
             } else {
                 long success = steps.stream().filter(s -> coordinator.getStatus(s) == SUCCEEDED).count();
                 long success = steps.stream().filter(s -> coordinator.getStatus(s) == SUCCEEDED).count();
                 long failed = steps.stream().filter(s -> coordinator.getStatus(s) == FAILED).count();
                 long failed = steps.stream().filter(s -> coordinator.getStatus(s) == FAILED).count();
                 long skipped = steps.stream().filter(s -> coordinator.getStatus(s) == SKIPPED).count();
                 long skipped = steps.stream().filter(s -> coordinator.getStatus(s) == SKIPPED).count();
-                print(isAborted ? ABORTED_SUMMARY : FAILURE_SUMMARY,
+                print(isAborted ? ABORTED_SUMMARY : FAILURE_SUMMARY, duration,
                       color(FAILED), color(SUCCEEDED), success,
                       color(FAILED), color(SUCCEEDED), success,
                       color(FAILED), failed, color(SKIPPED), skipped, color(null));
                       color(FAILED), failed, color(SKIPPED), skipped, color(null));
             }
             }
@@ -281,6 +284,17 @@ public final class Main {
         }
         }
     }
     }
 
 
+    // Formats time duration
+    private static String formatDuration(int totalSeconds) {
+        int seconds = totalSeconds % 60;
+        int totalMinutes = totalSeconds / 60;
+        int minutes = totalMinutes % 60;
+        int hours = totalMinutes / 60;
+        return hours > 0 ?
+                String.format("%d:%02d:%02d", hours, minutes, seconds) :
+                String.format("%d:%02d", minutes, seconds);
+    }
+
     // Shutdown hook to report status even when aborted.
     // Shutdown hook to report status even when aborted.
     private class ShutdownHook extends Thread {
     private class ShutdownHook extends Thread {
         @Override
         @Override

@@ -43,6 +43,9 @@ class ScenarioStore {
     private final List<StepEvent> events = Lists.newArrayList();
     private final List<StepEvent> events = Lists.newArrayList();
     private final Map<String, Status> statusMap = Maps.newConcurrentMap();
     private final Map<String, Status> statusMap = Maps.newConcurrentMap();
 
 
+    private long startTime = Long.MAX_VALUE;
+    private long endTime = Long.MIN_VALUE;
+
     /**
     /**
      * Creates a new scenario store for the specified process flow.
      * Creates a new scenario store for the specified process flow.
      *
      *
@@ -69,6 +72,8 @@ class ScenarioStore {
             PropertiesConfiguration cfg = new PropertiesConfiguration(storeFile);
             PropertiesConfiguration cfg = new PropertiesConfiguration(storeFile);
             cfg.clear();
             cfg.clear();
             cfg.save();
             cfg.save();
+            startTime = Long.MAX_VALUE;
+            endTime = Long.MIN_VALUE;
         } catch (ConfigurationException e) {
         } catch (ConfigurationException e) {
             print("Unable to store file %s", storeFile);
             print("Unable to store file %s", storeFile);
         }
         }
@@ -156,6 +161,8 @@ class ScenarioStore {
     private synchronized void add(StepEvent event) {
     private synchronized void add(StepEvent event) {
         events.add(event);
         events.add(event);
         statusMap.put(event.name(), event.status());
         statusMap.put(event.name(), event.status());
+        startTime = Math.min(startTime, event.time());
+        endTime = Math.max(endTime, event.time());
     }
     }
 
 
     /**
     /**
@@ -198,4 +205,22 @@ class ScenarioStore {
         }
         }
     }
     }
 
 
+    /**
+     * Returns the scenario run start time.
+     *
+     * @return start time in mills since start of epoch
+     */
+    public long startTime() {
+        return startTime;
+    }
+
+    /**
+     * Returns the scenario run end time or current time if the scenario
+     * is still running.
+     *
+     * @return end time (or current time) in mills since start of epoch
+     */
+    public long endTime() {
+        return endTime > 0 ? endTime : System.currentTimeMillis();
+    }
 }
 }