Use consistent timer instance, and set meaningful message timestamps

4 files changed, 24 insertions, 20 deletions

diff --git a/vespaclient-core/src/main/java/com/yahoo/clientmetrics/MessageTypeMetricSet.java b/vespaclient-core/src/main/java/com/yahoo/clientmetrics/MessageTypeMetricSet.java
index 46ad5ebfab6..8b798d4b76e 100644
--- a/vespaclient-core/src/main/java/com/yahoo/clientmetrics/MessageTypeMetricSet.java
+++ b/vespaclient-core/src/main/java/com/yahoo/clientmetrics/MessageTypeMetricSet.java
@@ -1,6 +1,7 @@
 // Copyright Yahoo. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
 package com.yahoo.clientmetrics;
 
+import com.yahoo.concurrent.Timer;
 import com.yahoo.documentapi.messagebus.protocol.DocumentIgnoredReply;
 import com.yahoo.documentapi.messagebus.protocol.DocumentProtocol;
 import com.yahoo.messagebus.Reply;
@@ -12,21 +13,24 @@ import java.util.Map;
 import java.util.stream.Stream;
 
 /**
-* @author thomasg
+* @author Thomas Gundersen
 */
 public class MessageTypeMetricSet {
+
     public long latency_total;
     public long latency_min = Long.MAX_VALUE;
     public long latency_max = Long.MIN_VALUE;
     public long count = 0;
     public long ignored = 0;
     public long errorCount = 0;
+    public final Timer timer;
     private final Map<String, Long> errorCounts = new HashMap<>();
 
     private final String msgName;
 
-    public MessageTypeMetricSet(String msgName) {
+    MessageTypeMetricSet(String msgName, Timer timer) {
         this.msgName = msgName;
+        this.timer = timer;
     }
 
     public String getMessageName() {
@@ -55,7 +59,7 @@ public class MessageTypeMetricSet {
     private void updateSuccessMetrics(Reply r) {
         if (!(r instanceof DocumentIgnoredReply)) {
             if (r.getMessage().getTimeReceived() != 0) {
-                long latency = (SystemTimer.INSTANCE.milliTime() - r.getMessage().getTimeReceived());
+                long latency = (timer.milliTime() - r.getMessage().getTimeReceived());
                 latency_max = Math.max(latency_max, latency);
                 latency_min = Math.min(latency_min, latency);
                 latency_total += latency;
diff --git a/vespaclient-core/src/main/java/com/yahoo/clientmetrics/RouteMetricSet.java b/vespaclient-core/src/main/java/com/yahoo/clientmetrics/RouteMetricSet.java
index ebf6246b034..96bcfd4239c 100644
--- a/vespaclient-core/src/main/java/com/yahoo/clientmetrics/RouteMetricSet.java
+++ b/vespaclient-core/src/main/java/com/yahoo/clientmetrics/RouteMetricSet.java
@@ -1,6 +1,8 @@
 // Copyright Yahoo. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
 package com.yahoo.clientmetrics;
 
+import com.yahoo.concurrent.SystemTimer;
+import com.yahoo.concurrent.Timer;
 import com.yahoo.messagebus.Reply;
 
 import java.util.HashMap;
@@ -12,6 +14,7 @@ import java.util.Map;
 public class RouteMetricSet {
 
     private final String route;
+    private final Timer timer;
     private final ProgressCallback callback;
     private final Map<Integer, MessageTypeMetricSet> typeMap = new HashMap<>();
 
@@ -20,18 +23,23 @@ public class RouteMetricSet {
         void done(RouteMetricSet route);
     }
 
-    public RouteMetricSet(String route, ProgressCallback callback) {
+    RouteMetricSet(String route, Timer timer, ProgressCallback callback) {
         this.route = route;
+        this.timer = timer;
         this.callback = callback;
     }
 
+    public RouteMetricSet(String route, ProgressCallback callback) {
+        this(route, SystemTimer.INSTANCE, callback);
+    }
+
     public Map<Integer, MessageTypeMetricSet> getMetrics() { return typeMap; }
 
     public void addReply(Reply r) {
         MessageTypeMetricSet type = typeMap.get(r.getMessage().getType());
         if (type == null) {
             String msgName = r.getMessage().getClass().getSimpleName().replace("Message", "");
-            type = new MessageTypeMetricSet(msgName);
+            type = new MessageTypeMetricSet(msgName, timer);
             typeMap.put(r.getMessage().getType(), type);
         }
 
diff --git a/vespaclient-java/src/test/java/com/yahoo/vespafeeder/BenchmarkProgressPrinterTest.java b/vespaclient-java/src/test/java/com/yahoo/vespafeeder/BenchmarkProgressPrinterTest.java
index 6eba29fe9cb..d5244e97118 100644
--- a/vespaclient-java/src/test/java/com/yahoo/vespafeeder/BenchmarkProgressPrinterTest.java
+++ b/vespaclient-java/src/test/java/com/yahoo/vespafeeder/BenchmarkProgressPrinterTest.java
@@ -20,11 +20,11 @@ public class BenchmarkProgressPrinterTest {
         ByteArrayOutputStream output = new ByteArrayOutputStream();
         ManualTimer timer = new ManualTimer();
         BenchmarkProgressPrinter printer = new BenchmarkProgressPrinter(timer, new PrintStream(output));
-        RouteMetricSet metrics = new RouteMetricSet("foobar", printer);
+        RouteMetricSet metrics = new RouteMetricSet("foobar", timer, printer);
 
         {
             EmptyReply reply = new EmptyReply();
-            reply.setMessage(PutDocumentMessage.createEmpty().setTimeReceived(1));
+            reply.setMessage(PutDocumentMessage.createEmpty().setTimeReceived(-1));
             metrics.addReply(reply);
         }
 
@@ -32,13 +32,13 @@ public class BenchmarkProgressPrinterTest {
 
         {
             EmptyReply reply = new EmptyReply();
-            reply.setMessage(PutDocumentMessage.createEmpty().setTimeReceived(2));
+            reply.setMessage(PutDocumentMessage.createEmpty().setTimeReceived(-1));
             metrics.addReply(reply);
         }
 
         {
             EmptyReply reply = new EmptyReply();
-            reply.setMessage(UpdateDocumentMessage.createEmpty().setTimeReceived(3));
+            reply.setMessage(UpdateDocumentMessage.createEmpty().setTimeReceived(-1));
             metrics.addReply(reply);
         }
 
@@ -46,7 +46,7 @@ public class BenchmarkProgressPrinterTest {
 
         {
             EmptyReply reply = new EmptyReply();
-            reply.setMessage(UpdateDocumentMessage.createEmpty().setTimeReceived(4));
+            reply.setMessage(UpdateDocumentMessage.createEmpty().setTimeReceived(-1));
             reply.addError(new com.yahoo.messagebus.Error(32, "foo"));
             metrics.addReply(reply);
         }
@@ -55,7 +55,7 @@ public class BenchmarkProgressPrinterTest {
 
         {
             EmptyReply reply = new EmptyReply();
-            reply.setMessage(UpdateDocumentMessage.createEmpty().setTimeReceived(5));
+            reply.setMessage(UpdateDocumentMessage.createEmpty().setTimeReceived(-1));
             reply.addError(new com.yahoo.messagebus.Error(64, "bar"));
             metrics.addReply(reply);
         }
diff --git a/vespajlib/src/main/java/com/yahoo/concurrent/Timer.java b/vespajlib/src/main/java/com/yahoo/concurrent/Timer.java
index 46d72f6d5ad..9328039aae6 100644
--- a/vespajlib/src/main/java/com/yahoo/concurrent/Timer.java
+++ b/vespajlib/src/main/java/com/yahoo/concurrent/Timer.java
@@ -22,14 +22,6 @@ public interface Timer {
     long milliTime();
     long creationNanos = System.nanoTime(); // Avoid monotonic timer overflow for the first 146 years of JVM uptime.
     Timer monotonic = () -> TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - creationNanos);
-    static Timer wrap(Clock original) {
-        return new Timer() {
-            private final Clock clock = original;
-
-            @Override
-            public long milliTime() {
-                return clock.millis();
-            }
-        }; }
+    static Timer wrap(Clock original) { return original::millis; }
     default Instant instant() { return Instant.ofEpochMilli(milliTime()); }
 }