Improve benchmark output from vespa-feed-client

vespa-feed-client-api/abi-spec.json

@@ -302,28 +302,47 @@
     ],
     "fields" : [ ]
   },
+  "ai.vespa.feed.client.OperationStats$Response" : {
+    "superClass" : "java.lang.Object",
+    "interfaces" : [ ],
+    "attributes" : [
+      "public"
+    ],
+    "methods" : [
+      "public void <init>(long, long, long, long, long, long, double)",
+      "public long count()",
+      "public long averageLatencyMillis()",
+      "public long minLatencyMillis()",
+      "public long maxLatencyMillis()",
+      "public long bytesReceived()",
+      "public double rate()",
+      "public java.lang.String toString()"
+    ],
+    "fields" : [ ]
+  },
   "ai.vespa.feed.client.OperationStats" : {
     "superClass" : "java.lang.Object",
     "interfaces" : [ ],
     "attributes" : [
       "public"
     ],
     "methods" : [
-      "public void <init>(double, long, java.util.Map, long, long, long, long, long, long, long, long)",
-      "public ai.vespa.feed.client.OperationStats since(ai.vespa.feed.client.OperationStats)",
+      "public void <init>(double, long, long, long, long, long, long, long, long, java.util.Map)",
       "public long requests()",
       "public long responses()",
       "public long successes()",
-      "public java.util.Map responsesByCode()",
+      "public java.util.Map statsByCode()",
+      "public java.util.Optional response(int)",
       "public long exceptions()",
       "public long inflight()",
       "public long averageLatencyMillis()",
       "public long minLatencyMillis()",
       "public long maxLatencyMillis()",
       "public long bytesSent()",
       "public long bytesReceived()",
-      "public boolean equals(java.lang.Object)",
-      "public int hashCode()",
+      "public long operationAverageLatencyMillis()",
+      "public long operationMinLatencyMillis()",
+      "public long operationMaxLatencyMillis()",
       "public java.lang.String toString()"
     ],
     "fields" : [ ]

vespa-feed-client-api/src/main/java/ai/vespa/feed/client/OperationStats.java

@@ -2,63 +2,40 @@
 package ai.vespa.feed.client;
 
 import java.util.Map;
-import java.util.Objects;
-import java.util.stream.Collectors;
+import java.util.Optional;
 
 /**
  * Statistics for feed operations over HTTP against a Vespa cluster.
  *
  * @author jonmv
+ * @author bjorncs
  */
 public class OperationStats {
 
     private final double duration;
     private final long requests;
-    private final Map<Integer, Long> responsesByCode;
     private final long inflight;
     private final long targetInflight;
     private final long exceptions;
+    private final long bytesSent;
     private final long averageLatencyMillis;
     private final long minLatencyMillis;
     private final long maxLatencyMillis;
-    private final long bytesSent;
-    private final long bytesReceived;
+    private final Map<Integer, Response> statsByCode;
 
-    public OperationStats(double duration, long requests, Map<Integer, Long> responsesByCode, long exceptions,
-                          long inflight, long targetInFlight, long averageLatencyMillis, long minLatencyMillis,
-                          long maxLatencyMillis, long bytesSent, long bytesReceived) {
+    public OperationStats(double duration, long requests, long exceptions, long inflight, long targetInFlight, long bytesSent,
+                          long averageLatencyMillis, long minLatencyMillis, long maxLatencyMillis,
+                          Map<Integer, Response> statsByCode) {
         this.duration = duration;
         this.requests = requests;
-        this.responsesByCode = responsesByCode;
         this.exceptions = exceptions;
         this.inflight = inflight;
         this.targetInflight = targetInFlight;
+        this.bytesSent = bytesSent;
         this.averageLatencyMillis = averageLatencyMillis;
         this.minLatencyMillis = minLatencyMillis;
         this.maxLatencyMillis = maxLatencyMillis;
-        this.bytesSent = bytesSent;
-        this.bytesReceived = bytesReceived;
-    }
-
-    /** Returns the difference between this and the initial.
-     *  Min and max latency, inflight and targetInflight are not modified.
-     */
-    public OperationStats since(OperationStats initial) {
-        return new OperationStats(duration - initial.duration,
-                         requests - initial.requests,
-                                  responsesByCode.entrySet().stream()
-                                                 .collect(Collectors.toMap(Map.Entry::getKey,
-                                                                           entry -> entry.getValue() - initial.responsesByCode.getOrDefault(entry.getKey(), 0L))),
-                                  exceptions - initial.exceptions,
-                                  inflight,
-                                  targetInflight,
-                                  responsesByCode.size() == initial.responsesByCode.size() ? 0 :
-                                    (averageLatencyMillis * responsesByCode.size() - initial.averageLatencyMillis * initial.responsesByCode.size())
-                                  / (responsesByCode.size() - initial.responsesByCode.size()),
-                                  minLatencyMillis,
-                                  maxLatencyMillis,
-                                  bytesSent - initial.bytesSent,
-                                  bytesReceived - initial.bytesReceived);
+        this.statsByCode = statsByCode;
     }
 
     /** Number of HTTP requests attempted. */
@@ -68,18 +45,21 @@ public long requests() {
 
     /** Number of HTTP responses received. */
     public long responses() {
-        return requests - inflight - exceptions;
+        return statsByCode.values().stream().mapToLong(r -> r.count).sum();
     }
 
     /** Number of 200 OK HTTP responses received. */
     public long successes() {
-        return responsesByCode.getOrDefault(200, 0L);
+        var okStats = statsByCode.get(200);
+        if (okStats == null) return 0;
+        return okStats.count;
     }
 
-    /** Number of HTTP responses by status code. */
-    public Map<Integer, Long> responsesByCode() {
-        return responsesByCode;
-    }
+    /** Statistics per response code. */
+    public Map<Integer, Response> statsByCode() { return statsByCode; }
+
+    /** Statistics for the given code. */
+    public Optional<Response> response(int code) { return Optional.ofNullable(statsByCode.get(code)); }
 
     /** Number of exceptions (instead of responses). */
     public long exceptions() {
@@ -93,17 +73,20 @@ public long inflight() {
 
     /** Average request-response latency, or -1.  */
     public long averageLatencyMillis() {
-        return averageLatencyMillis;
+        var responses = responses();
+        if (responses == 0) return -1;
+        var totalLatencyMillis = statsByCode.values().stream().mapToLong(r -> r.totalLatencyMillis).sum();
+        return totalLatencyMillis / responses;
     }
 
     /** Minimum request-response latency, or -1.  */
     public long minLatencyMillis() {
-        return minLatencyMillis;
+        return statsByCode.values().stream().mapToLong(r -> r.minLatencyMillis).min().orElse(-1L);
     }
 
     /** Maximum request-response latency, or -1.  */
     public long maxLatencyMillis() {
-        return maxLatencyMillis;
+        return statsByCode.values().stream().mapToLong(r -> r.maxLatencyMillis).max().orElse(-1L);
     }
 
     /** Number of bytes sent, for HTTP requests with a response. */
@@ -113,39 +96,85 @@ public long bytesSent() {
 
     /** Number of bytes received in HTTP responses. */
     public long bytesReceived() {
-        return bytesReceived;
+        return statsByCode.values().stream().mapToLong(r -> r.bytesReceived).sum();
     }
 
-    @Override
-    public boolean equals(Object o) {
-        if (this == o) return true;
-        if (o == null || getClass() != o.getClass()) return false;
-        OperationStats that = (OperationStats) o;
-        return requests == that.requests && inflight == that.inflight && exceptions == that.exceptions && averageLatencyMillis == that.averageLatencyMillis && minLatencyMillis == that.minLatencyMillis && maxLatencyMillis == that.maxLatencyMillis && bytesSent == that.bytesSent && bytesReceived == that.bytesReceived && responsesByCode.equals(that.responsesByCode);
-    }
+    /**
+     * Operation latency is the time from the initial HTTP request is sent until the operation was successfully completed
+     * as observed by the client. Time spent on retrying the request will be included. Operations that eventually failed are not included.
+     * @return average latency in milliseconds
+     */
+    public long operationAverageLatencyMillis() { return averageLatencyMillis; }
 
-    @Override
-    public int hashCode() {
-        return Objects.hash(requests, responsesByCode, inflight, exceptions, averageLatencyMillis, minLatencyMillis, maxLatencyMillis, bytesSent, bytesReceived);
-    }
+    /**
+     * @see #operationAverageLatencyMillis()
+     * @return minimum latency as milliseconds
+     */
+    public long operationMinLatencyMillis() { return minLatencyMillis; }
+
+    /**
+     * @see #operationAverageLatencyMillis()
+     * @return max latency as milliseconds
+     */
+    public long operationMaxLatencyMillis() { return maxLatencyMillis; }
 
     @Override
     public String toString() {
-        Map<Integer, Double> rateByCode = responsesByCode.entrySet().stream()
-                .collect(Collectors.toMap(Map.Entry::getKey, e -> e.getValue()/duration));
-        return "Stats{" +
-               "requests=" + requests +
-               ", responsesByCode=" + responsesByCode +
-               ", responseRateByCode=" + rateByCode +
-               ", exceptions=" + exceptions +
-               ", inflight=" + inflight +
-               ", targetInflight=" + targetInflight +
-               ", averageLatencyMillis=" + averageLatencyMillis +
-               ", minLatencyMillis=" + minLatencyMillis +
-               ", maxLatencyMillis=" + maxLatencyMillis +
-               ", bytesSent=" + bytesSent +
-               ", bytesReceived=" + bytesReceived +
-               '}';
+        return "OperationStats{" +
+                "duration=" + duration +
+                ", requests=" + requests +
+                ", inflight=" + inflight +
+                ", targetInflight=" + targetInflight +
+                ", exceptions=" + exceptions +
+                ", bytesSent=" + bytesSent +
+                ", averageLatencyMillis=" + averageLatencyMillis +
+                ", minLatencyMillis=" + minLatencyMillis +
+                ", maxLatencyMillis=" + maxLatencyMillis +
+                ", statsByCode=" + statsByCode +
+                '}';
+    }
+
+    public static class Response {
+        private final long count;
+        private final long totalLatencyMillis;
+        private final long averageLatencyMillis;
+        private final long minLatencyMillis;
+        private final long maxLatencyMillis;
+        private final long bytesReceived;
+        private final double rate;
+
+        public Response(
+                long count, long totalLatencyMillis, long averageLatencyMillis, long minLatencyMillis,
+                long maxLatencyMillis, long bytesReceived, double rate) {
+            this.count = count;
+            this.totalLatencyMillis = totalLatencyMillis;
+            this.averageLatencyMillis = averageLatencyMillis;
+            this.minLatencyMillis = minLatencyMillis;
+            this.maxLatencyMillis = maxLatencyMillis;
+            this.bytesReceived = bytesReceived;
+            this.rate = rate;
+        }
+
+        // Generate getters for all fields. Should have the same name as the field, and written as a single line
+        public long count() { return count; }
+        public long averageLatencyMillis() { return averageLatencyMillis; }
+        public long minLatencyMillis() { return minLatencyMillis; }
+        public long maxLatencyMillis() { return maxLatencyMillis; }
+        public long bytesReceived() { return bytesReceived; }
+        public double rate() { return rate; }
+
+        @Override
+        public String toString() {
+            return "Response{" +
+                    "count=" + count +
+                    ", totalLatencyMillis=" + totalLatencyMillis +
+                    ", averageLatencyMillis=" + averageLatencyMillis +
+                    ", minLatencyMillis=" + minLatencyMillis +
+                    ", maxLatencyMillis=" + maxLatencyMillis +
+                    ", bytesReceived=" + bytesReceived +
+                    ", rate=" + rate +
+                    '}';
+        }
     }
 
 }

vespa-feed-client-cli/src/main/java/ai/vespa/feed/client/impl/CliClient.java

@@ -237,11 +237,32 @@ static void printBenchmarkResult(long durationNanos, long successes, long failur
             writeFloatField(generator, "http.response.latency.millis.avg", stats.averageLatencyMillis(), 3);
             writeFloatField(generator, "http.response.latency.millis.max", stats.maxLatencyMillis(), 3);
 
-            generator.writeObjectFieldStart("http.response.code.counts");
-            for (Map.Entry<Integer, Long> entry : stats.responsesByCode().entrySet())
-                generator.writeNumberField(Integer.toString(entry.getKey()), entry.getValue());
-            generator.writeEndObject();
-
+            // Hide new experimental output behind feature flag
+            if (System.getenv("VESPA_EXTENDED_STATS") != null) {
+                generator.writeObjectFieldStart("operation.latency");
+                generator.writeNumberField("min", stats.operationMinLatencyMillis());
+                generator.writeNumberField("avg", stats.operationAverageLatencyMillis());
+                generator.writeNumberField("max", stats.operationMaxLatencyMillis());
+                generator.writeEndObject();
+
+                generator.writeObjectFieldStart("http.response");
+                for (var e : stats.statsByCode().entrySet()) {
+                    generator.writeObjectFieldStart(Integer.toString(e.getKey()));
+                    generator.writeNumberField("count", e.getValue().count());
+                    generator.writeObjectFieldStart("latency");
+                    generator.writeNumberField("min", e.getValue().minLatencyMillis());
+                    generator.writeNumberField("avg", e.getValue().averageLatencyMillis());
+                    generator.writeNumberField("max", e.getValue().maxLatencyMillis());
+                    generator.writeEndObject();
+                    generator.writeEndObject();
+                }
+                generator.writeEndObject();
+            } else {
+                generator.writeObjectFieldStart("http.response.code.counts");
+                for (Map.Entry<Integer, OperationStats.Response> entry : stats.statsByCode().entrySet())
+                    generator.writeNumberField(Integer.toString(entry.getKey()), entry.getValue().count());
+                generator.writeEndObject();
+            }
             generator.writeEndObject();
         }
     }

vespa-feed-client/pom.xml

@@ -46,6 +46,11 @@
       <artifactId>junit-jupiter</artifactId>
       <scope>test</scope>
     </dependency>
+    <dependency>
+      <groupId>org.mockito</groupId>
+      <artifactId>mockito-core</artifactId>
+      <scope>test</scope>
+    </dependency>
   </dependencies>
 
   <build>