Less and improved logging

Some other minor changes as well, but no functional changes

3 files changed, 14 insertions, 19 deletions

diff --git a/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/CompressedFileReference.java b/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/CompressedFileReference.java
index a1ad5c8a200..ddab35ba14d 100644
--- a/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/CompressedFileReference.java
+++ b/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/CompressedFileReference.java
@@ -75,7 +75,6 @@ public class CompressedFileReference {
         int entries = 0;
         ArchiveEntry entry;
         while ((entry = archiveInputStream.getNextEntry()) != null) {
-            log.log(LogLevel.DEBUG, "Unpacking " + entry.getName());
             File outFile = new File(outputFile, entry.getName());
             if (entry.isDirectory()) {
                 if (!(outFile.exists() && outFile.isDirectory())) {
diff --git a/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReceiver.java b/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReceiver.java
index c4487252e27..ff9efc74929 100644
--- a/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReceiver.java
+++ b/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReceiver.java
@@ -96,9 +96,9 @@ public class FileReceiver {
             try {
                 Files.write(inprogressFile.toPath(), part, StandardOpenOption.WRITE, StandardOpenOption.APPEND);
             } catch (IOException e) {
-                log.log(LogLevel.ERROR, "Failed writing to file(" + inprogressFile.toPath() + "): " + e.getMessage(), e);
+                log.log(LogLevel.ERROR, "Failed writing to file (" + inprogressFile.toPath() + "): " + e.getMessage(), e);
                 inprogressFile.delete();
-                throw new RuntimeException("Failed writing to file(" + inprogressFile.toPath() + "): ", e);
+                throw new RuntimeException("Failed writing to file (" + inprogressFile.toPath() + "): ", e);
             }
             currentFileSize += part.length;
             currentPartId++;
@@ -114,7 +114,6 @@ public class FileReceiver {
                 // Unpack if necessary
                 if (fileType == FileReferenceData.Type.compressed) {
                     File decompressedDir = Files.createTempDirectory(tmpDir.toPath(), "archive").toFile();
-                    log.log(LogLevel.DEBUG, () -> "Archived file, unpacking " + inprogressFile + " to " + decompressedDir);
                     CompressedFileReference.decompress(inprogressFile, decompressedDir);
                     moveFileToDestination(decompressedDir, fileReferenceDir);
                 } else {
@@ -256,7 +255,7 @@ public class FileReceiver {
             retval = 1;
         }
         double completeness = (double) session.currentFileSize / (double) session.fileSize;
-        log.log(LogLevel.DEBUG, () -> String.format("%.1f percent of '%s' downloaded", completeness * 100, reference.value()));
+        log.log(LogLevel.SPAM, () -> String.format("%.1f percent of '%s' downloaded", completeness * 100, reference.value()));
         downloader.setDownloadStatus(reference, completeness);
         req.returnValues().add(new Int32Value(retval));
     }
diff --git a/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReferenceDownloader.java b/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReferenceDownloader.java
index c4fe257c991..f1d31156d79 100644
--- a/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReferenceDownloader.java
+++ b/filedistribution/src/main/java/com/yahoo/vespa/filedistribution/FileReferenceDownloader.java
@@ -12,11 +12,11 @@ import com.yahoo.vespa.config.ConnectionPool;
 
 import java.io.File;
 import java.time.Duration;
+import java.time.Instant;
 import java.util.HashMap;
 import java.util.LinkedHashMap;
 import java.util.Map;
 import java.util.Optional;
-import java.util.concurrent.CompletableFuture;
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Executors;
 import java.util.concurrent.TimeUnit;
@@ -54,12 +54,12 @@ public class FileReferenceDownloader {
         new FileReceiver(connectionPool.getSupervisor(), this, downloadDirectory, tmpDirectory);
     }
 
-    private void startDownload(Duration timeout, FileReferenceDownload fileReferenceDownload) {
+    private void startDownload(FileReferenceDownload fileReferenceDownload) {
         FileReference fileReference = fileReferenceDownload.fileReference();
-        long end = System.currentTimeMillis() + timeout.toMillis();
+        Instant end = Instant.now().plus(downloadTimeout);
         boolean downloadStarted = false;
         int retryCount = 0;
-        while ((System.currentTimeMillis() < end) && !downloadStarted) {
+        do {
             try {
                 if (startDownloadRpc(fileReferenceDownload, retryCount)) {
                     downloadStarted = true;
@@ -69,7 +69,7 @@ public class FileReferenceDownloader {
                 }
             }
             catch (InterruptedException e) { /* ignored */}
-        }
+        } while (Instant.now().isBefore(end) && !downloadStarted);
 
         if ( !downloadStarted) {
             fileReferenceDownload.future().completeExceptionally(new RuntimeException("Failed getting file reference '" + fileReference.value() + "'"));
@@ -86,7 +86,7 @@ public class FileReferenceDownloader {
             downloads.put(fileReference, fileReferenceDownload);
             downloadStatus.put(fileReference, 0.0);
         }
-        downloadExecutor.submit(() -> startDownload(downloadTimeout, fileReferenceDownload));
+        downloadExecutor.submit(() -> startDownload(fileReferenceDownload));
     }
 
     void completedDownloading(FileReference fileReference, File file) {
@@ -116,10 +116,10 @@ public class FileReferenceDownloader {
         request.parameters().add(new StringValue(fileReference));
         request.parameters().add(new Int32Value(fileReferenceDownload.downloadFromOtherSourceIfNotFound() ? 0 : 1));
 
-        execute(request, connection);
+        connection.invokeSync(request, (double) rpcTimeout.getSeconds());
         Level logLevel = (retryCount > 0 ? LogLevel.INFO : LogLevel.DEBUG);
         if (validateResponse(request)) {
-            log.log(logLevel, () -> "Request callback, OK. Req: " + request + "\nSpec: " + connection);
+            log.log(logLevel, () -> "Request callback, OK. Req: " + request + "\nSpec: " + connection + ", retry count " + retryCount);
             if (request.returnValues().get(0).asInt32() == 0) {
                 log.log(logLevel, () -> "Found file reference '" + fileReference + "' available at " + connection.getAddress());
                 return true;
@@ -129,8 +129,9 @@ public class FileReferenceDownloader {
                 return false;
             }
         } else {
-            log.log(logLevel, "Request failed. Req: " + request + "\nSpec: " + connection.getAddress() +
-                    ", error code: " + request.errorCode() + ", set error for connection and use another for next request");
+            log.log(logLevel, () -> "Request failed. Req: " + request + "\nSpec: " + connection.getAddress() +
+            ", error code: " + request.errorCode() + ", set error for spec, use another spec for next request" +
+            ", retry count " + retryCount);
             connectionPool.setError(connection, request.errorCode());
             return false;
         }
@@ -148,10 +149,6 @@ public class FileReferenceDownloader {
         }
     }
 
-    private void execute(Request request, Connection connection) {
-        connection.invokeSync(request, (double) rpcTimeout.getSeconds());
-    }
-
     private boolean validateResponse(Request request) {
         if (request.isError()) {
             return false;