Add elapsed and start time to json summary output (#394)

Closes #393

Author: bpkroth

src/main/java/com/oltpbenchmark/Results.java

@@ -28,6 +28,7 @@
 
 public final class Results {
 
+    private final long startTimestampMs;
     private final long nanoseconds;
     private final int measuredRequests;
     private final DistributionStatistics distributionStatistics;
@@ -40,8 +41,9 @@ public final class Results {
     private final Histogram<TransactionType> retryDifferent = new Histogram<>(false);
     private final Map<TransactionType, Histogram<String>> abortMessages = new HashMap<>();
 
-    public Results(long nanoseconds, int measuredRequests, DistributionStatistics distributionStatistics, final List<LatencyRecord.Sample> latencySamples) {
-        this.nanoseconds = nanoseconds;
+    public Results(long startTimestampMs, long elapsedNanoseconds, int measuredRequests, DistributionStatistics distributionStatistics, final List<LatencyRecord.Sample> latencySamples) {
+        this.startTimestampMs = startTimestampMs;
+        this.nanoseconds = elapsedNanoseconds;
         this.measuredRequests = measuredRequests;
         this.distributionStatistics = distributionStatistics;
 
@@ -98,6 +100,10 @@ public List<Sample> getLatencySamples() {
         return latencySamples;
     }
 
+    public long getStartTimestampMs() {
+        return startTimestampMs;
+    }
+
     public long getNanoseconds() {
         return nanoseconds;
     }

src/main/java/com/oltpbenchmark/ThreadBench.java

@@ -113,6 +113,7 @@ private Results runRateLimitedMultiPhase() {
 
         // long measureStart = start;
 
+        long start_ts = System.currentTimeMillis();
         long start = System.nanoTime();
         long warmupStart = System.nanoTime();
         long warmup = warmupStart;
@@ -314,7 +315,7 @@ private Results runRateLimitedMultiPhase() {
             }
             DistributionStatistics stats = DistributionStatistics.computeStatistics(latencies);
 
-            Results results = new Results(measureEnd - start, requests, stats, samples);
+            Results results = new Results(start_ts, measureEnd - start, requests, stats, samples);
 
             // Compute transaction histogram
             Set<TransactionType> txnTypes = new HashSet<>();

src/main/java/com/oltpbenchmark/util/JSONUtil.java

@@ -82,7 +82,27 @@ public static Field[] getSerializableFields(Class<?> clazz, String... fieldsToEx
      */
     public static String format(String json) {
         try {
-            return (JSONUtil.format(new JSONObject(json)));
+            return (JSONUtil.format(new JSONObject(json){
+                /**
+                 * changes the value of JSONObject.map to a LinkedHashMap in order to maintain
+                 * order of keys.
+                 * See Also: https://stackoverflow.com/a/62476486
+                 */
+                @Override
+                public JSONObject put(String key, Object value) throws JSONException {
+                    try {
+                        Field map = JSONObject.class.getDeclaredField("map");
+                        map.setAccessible(true);
+                        Object mapValue = map.get(this);
+                        if (!(mapValue instanceof LinkedHashMap)) {
+                            map.set(this, new LinkedHashMap<>());
+                        }
+                    } catch (NoSuchFieldException | IllegalAccessException e) {
+                        throw new RuntimeException(e);
+                    }
+                    return super.put(key, value);
+                }
+            }));
         } catch (RuntimeException ex) {
             throw ex;
         } catch (Exception ex) {

src/main/java/com/oltpbenchmark/util/ResultWriter.java

@@ -99,19 +99,22 @@ public void writeConfig(PrintStream os) throws ConfigurationException {
     }
 
     public void writeSummary(PrintStream os) {
-        Map<String, Object> summaryMap = new TreeMap<>();
+        Map<String, Object> summaryMap = new LinkedHashMap<>();
         TimeZone.setDefault(TimeZone.getTimeZone("UTC"));
         Date now = new Date();
+        summaryMap.put("Start timestamp (milliseconds)", results.getStartTimestampMs());
         summaryMap.put("Current Timestamp (milliseconds)", now.getTime());
+        summaryMap.put("Elapsed Time (nanoseconds)", results.getNanoseconds());
         summaryMap.put("DBMS Type", dbType);
         summaryMap.put("DBMS Version", collector.collectVersion());
         summaryMap.put("Benchmark Type", benchType);
-        summaryMap.put("Latency Distribution", results.getDistributionStatistics().toMap());
-        summaryMap.put("Throughput (requests/second)", results.requestsPerSecondThroughput());
-        summaryMap.put("Goodput (requests/second)", results.requestsPerSecondGoodput());
+        summaryMap.put("Measured Requests", results.getMeasuredRequests());
         for (String field : BENCHMARK_KEY_FIELD) {
             summaryMap.put(field, expConf.getString(field));
         }
+        summaryMap.put("Latency Distribution", results.getDistributionStatistics().toMap());
+        summaryMap.put("Throughput (requests/second)", results.requestsPerSecondThroughput());
+        summaryMap.put("Goodput (requests/second)", results.requestsPerSecondGoodput());
         os.println(JSONUtil.format(JSONUtil.toJSONString(summaryMap)));
     }