Fixed some collection and display of performance metrics

Author: dgant

src/main/java/bwapi/BWClient.java

@@ -27,7 +27,7 @@ public Game getGame() {
      * Returns JBWAPI performance metrics.
      * Metrics will be mostly empty if metrics collection isn't timersEnabled in the bot configuration
      */
-    public PerformanceMetrics performanceMetrics() {
+    public PerformanceMetrics getPerformanceMetrics() {
         return performanceMetrics;
     }
 

src/main/java/bwapi/BWClientConfiguration.java

@@ -53,7 +53,7 @@ public class BWClientConfiguration {
      * Enables collection of diagnostics.
      * When timersEnabled, JBWAPI collects and publishes performance metrics.
      */
-    public boolean diagnosePerformance = false;
+    public boolean collectPerformanceMetrics = false;
 
     /**
      * Checks that the configuration is in a valid state. Throws an IllegalArgumentException if it isn't.

src/main/java/bwapi/BotWrapper.java

@@ -126,23 +126,25 @@ private Thread createBotThread() {
                     frameBuffer.lockSize.unlock();
                 }
                 game.clientData().setBuffer(frameBuffer.peek());
-                performanceMetrics.frameBufferSize.record(frameBuffer.framesBuffered());
+                performanceMetrics.frameBufferSize.record(frameBuffer.framesBuffered() - 1);
                 handleEvents();
                 frameBuffer.dequeue();
             }
         });
     }
 
     private void handleEvents() {
-        performanceMetrics.botResponse.time(() -> {
-            ClientData.GameData gameData = game.clientData().gameData();
-            for (int i = 0; i < gameData.getEventCount(); i++) {
-                ClientData.Event event = gameData.getEvents(i);
-                EventHandler.operation(eventListener, game, event);
-                if (event.getType() == EventType.MatchEnd) {
-                    gameOver = true;
-                }
+        ClientData.GameData gameData = game.clientData().gameData();
+        if (gameData.getFrameCount() > 0 || ! configuration.asyncWaitOnFrameZero) {
+            performanceMetrics.botResponse.startTiming();
+        }
+        for (int i = 0; i < gameData.getEventCount(); i++) {
+            ClientData.Event event = gameData.getEvents(i);
+            EventHandler.operation(eventListener, game, event);
+            if (event.getType() == EventType.MatchEnd) {
+                gameOver = true;
             }
-        });
+        }
+        performanceMetrics.botResponse.stopTiming();
     }
 }

src/main/java/bwapi/PerformanceMetric.java

@@ -4,7 +4,7 @@
 
 public class PerformanceMetric {
     private final String name;
-    private final long maxThreshold;
+    private final long maxAllowed;
     public final boolean timerEnabled;
 
     public double minValue = Long.MAX_VALUE;
@@ -17,9 +17,9 @@ public class PerformanceMetric {
 
     private long timeStarted = 0;
 
-    PerformanceMetric(String name, long maxThreshold, boolean timerEnabled) {
+    PerformanceMetric(String name, long maxAllowed, boolean timerEnabled) {
         this.name = name;
-        this.maxThreshold = maxThreshold;
+        this.maxAllowed = maxAllowed;
         this.timerEnabled = timerEnabled;
     }
 
@@ -40,20 +40,19 @@ void startTiming() {
     void stopTiming() {
         if (!timerEnabled) return;
         if (timeStarted <= 0) return;
-        // Use nanosecond resolution timer,
-        // and record in units of milliseconds.
+        // Use nanosecond resolution timer, but record in units of milliseconds.
         long timeEnded = System.nanoTime();
         long timeDiff = timeEnded - timeStarted;
         timeStarted = 0;
-        record(timeDiff / 1000d);
+        record(timeDiff / 1000000d);
     }
 
     void record(double value) {
         minValue = Math.min(minValue, value);
         maxValue = Math.max(maxValue, value);
         avgValue = (avgValue * samples + value) / (samples + 1d);
         ++samples;
-        if (value > maxThreshold) {
+        if (value > maxAllowed) {
             avgValueExceeding = (avgValueExceeding * samplesExceeding + value) / (samplesExceeding + 1d);
             ++samplesExceeding;
         }
@@ -64,22 +63,24 @@ public String toString() {
         DecimalFormat formatter = new DecimalFormat("###,###.#");
         return name
                 + ": "
-                + samples
-                + " averaging "
-                + formatter.format(avgValue)
-                + " ["
-                + formatter.format(minValue)
-                + " - "
-                + formatter.format(maxValue)
-                + "] over "
-                + samples
-                + " samples"
-                + (samplesExceeding > 0
-                    ? ". "
-                        + samplesExceeding
-                        + " violations averaging "
-                        + formatter.format(avgValueExceeding)
-                    : "")
+                + (samples > 0
+                    ? formatter.format(samples)
+                        + " samples averaging "
+                        + formatter.format(avgValue)
+                        + " ["
+                        + formatter.format(minValue)
+                        + " - "
+                        + formatter.format(maxValue)
+                        + "] over "
+                        + samples
+                        + " samples"
+                        + (samplesExceeding > 0
+                            ? ". "
+                                + samplesExceeding
+                                + " violations averaging "
+                                + formatter.format(avgValueExceeding)
+                            : "")
+                    : "No samples")
                 + (interrupted > 0
                     ? ". Interrupted " + interrupted + " times"
                     : "");

src/main/java/bwapi/PerformanceMetrics.java

@@ -58,20 +58,21 @@ public class PerformanceMetrics {
     public PerformanceMetric botIdle;
 
     public PerformanceMetrics(BWClientConfiguration configuration) {
-        timersEnabled = configuration.diagnosePerformance;
+        timersEnabled = configuration.collectPerformanceMetrics;
         final int frameDurationBufferMs = 5;
         final int sideEffectsBufferMs = 1;
         final int realTimeFrameMs = 42;
         totalFrameDuration = new PerformanceMetric("Total frame duration", configuration.asyncFrameDurationMs + frameDurationBufferMs, timersEnabled);
         copyingToBuffer = new PerformanceMetric("Time copying to buffer", 5, timersEnabled);
         intentionallyBlocking = new PerformanceMetric("Intentionally blocking", 0, timersEnabled);
-        frameBufferSize = new PerformanceMetric("Frame buffer size", 0, timersEnabled);
+        frameBufferSize = new PerformanceMetric("Frames buffered", 0, timersEnabled);
         flushSideEffects = new PerformanceMetric("Flush side effects", sideEffectsBufferMs , timersEnabled);
         botResponse = new PerformanceMetric("Bot Responses", configuration.asyncFrameDurationMs, timersEnabled);
         bwapiResponse = new PerformanceMetric("BWAPI Responses", realTimeFrameMs, timersEnabled);
         botIdle = new PerformanceMetric("Bot idle", Long.MAX_VALUE, timersEnabled);
     }
 
+    @Override
     public String toString() {
         return "Performance metrics:"
                 + "\n" + totalFrameDuration.toString()