Log duration of name service dispatching

2 files changed, 15 insertions, 5 deletions

diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/dns/NameServiceQueue.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/dns/NameServiceQueue.java
index 4768577aa7b..684fb091d92 100644
--- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/dns/NameServiceQueue.java
+++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/dns/NameServiceQueue.java
@@ -74,7 +74,6 @@ public class NameServiceQueue {
         var queue = new NameServiceQueue(requests);
         for (int i = 0; i < n && !queue.requests.isEmpty(); i++) {
             var request = queue.requests.peek();
-            log.log(LogLevel.INFO, "Dispatching name service request: " + request);
             try {
                 request.dispatchTo(nameService);
                 queue.requests.poll();
diff --git a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/maintenance/NameServiceDispatcher.java b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/maintenance/NameServiceDispatcher.java
index 00a85bb9e4d..83460d8f05a 100644
--- a/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/maintenance/NameServiceDispatcher.java
+++ b/controller-server/src/main/java/com/yahoo/vespa/hosted/controller/maintenance/NameServiceDispatcher.java
@@ -1,12 +1,13 @@
 // Copyright 2019 Oath Inc. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
 package com.yahoo.vespa.hosted.controller.maintenance;
 
-import com.yahoo.vespa.curator.Lock;
+import com.yahoo.log.LogLevel;
 import com.yahoo.vespa.hosted.controller.Controller;
 import com.yahoo.vespa.hosted.controller.api.integration.dns.NameService;
 import com.yahoo.vespa.hosted.controller.dns.NameServiceQueue;
 import com.yahoo.vespa.hosted.controller.persistence.CuratorDb;
 
+import java.time.Clock;
 import java.time.Duration;
 
 /**
@@ -19,6 +20,7 @@ public class NameServiceDispatcher extends Maintainer {
 
     private static final int defaultRequestCount = 1;
 
+    private final Clock clock;
     private final CuratorDb db;
     private final NameService nameService;
     private final int requestCount;
@@ -29,6 +31,7 @@ public class NameServiceDispatcher extends Maintainer {
 
     public NameServiceDispatcher(Controller controller, Duration interval, JobControl jobControl, int requestCount) {
         super(controller, interval, jobControl);
+        this.clock = controller.clock();
         this.db = controller.curator();
         this.nameService = controller.serviceRegistry().nameService();
         this.requestCount = requestCount;
@@ -36,10 +39,18 @@ public class NameServiceDispatcher extends Maintainer {
 
     @Override
     protected void maintain() {
-        try (Lock lock = db.lockNameServiceQueue()) {
-            NameServiceQueue queue = db.readNameServiceQueue();
-            NameServiceQueue remaining = queue.dispatchTo(nameService, requestCount);
+        try (var lock = db.lockNameServiceQueue()) {
+            var queue = db.readNameServiceQueue();
+            var instant = clock.instant();
+            var remaining = queue.dispatchTo(nameService, requestCount);
             if (queue == remaining) return; // Queue unchanged
+
+            var dispatched = queue.last(requestCount);
+            if (!dispatched.requests().isEmpty()) {
+                log.log(LogLevel.INFO, "Dispatched name service request(s) in " +
+                                       Duration.between(instant, clock.instant()) +
+                                       ": " + dispatched.requests());
+            }
             db.writeNameServiceQueue(remaining);
         }
     }