Make ExperimentalStateTracker aware of DownloadProgressEvents

In the experimental UI, to be able to report appropriately about ongoing
downloads, we need to track their state, as updated by the DownloadProgressEvents.
Do so. Also report on ongoing downloads in the progress bar.

--
Change-Id: I668e963cd6da85ec598b23724066d366d465271f
Reviewed-on: https://cr.bazel.build/9114
PiperOrigin-RevId: 148899297
MOS_MIGRATED_REVID=148899297

4 files changed, 220 insertions, 2 deletions

diff --git a/src/main/java/com/google/devtools/build/lib/BUILD b/src/main/java/com/google/devtools/build/lib/BUILD
index 7bca1eb470..20047b5c3f 100644
--- a/src/main/java/com/google/devtools/build/lib/BUILD
+++ b/src/main/java/com/google/devtools/build/lib/BUILD
@@ -1065,6 +1065,7 @@ java_library(
         ":windows",
         "//src/main/java/com/google/devtools/build/docgen:docgen_javalib",
         "//src/main/java/com/google/devtools/build/lib/actions",
+        "//src/main/java/com/google/devtools/build/lib/bazel/repository/downloader",
         "//src/main/java/com/google/devtools/build/lib/buildeventstream/proto:build_event_stream_java_proto",
         "//src/main/java/com/google/devtools/build/lib/buildeventstream/transports",
         "//src/main/java/com/google/devtools/build/lib/cmdline",
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/ExperimentalStateTracker.java b/src/main/java/com/google/devtools/build/lib/runtime/ExperimentalStateTracker.java
index 2fa11972ac..c6efa08edd 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/ExperimentalStateTracker.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/ExperimentalStateTracker.java
@@ -19,6 +19,7 @@ import com.google.devtools.build.lib.actions.ActionStartedEvent;
 import com.google.devtools.build.lib.actions.ActionStatusMessage;
 import com.google.devtools.build.lib.analysis.AnalysisPhaseCompleteEvent;
 import com.google.devtools.build.lib.analysis.ConfiguredTarget;
+import com.google.devtools.build.lib.bazel.repository.downloader.DownloadProgressEvent;
 import com.google.devtools.build.lib.buildtool.ExecutionProgressReceiver;
 import com.google.devtools.build.lib.buildtool.buildevent.BuildCompleteEvent;
 import com.google.devtools.build.lib.buildtool.buildevent.BuildStartingEvent;
@@ -49,8 +50,12 @@ class ExperimentalStateTracker {
 
   static final long SHOW_TIME_THRESHOLD_SECONDS = 3;
   static final String ELLIPSIS = "...";
+  static final String FETCH_PREFIX = "    Fetching ";
+  static final String AND_MORE = " ...";
+
 
   static final int NANOS_PER_SECOND = 1000000000;
+  static final String URL_PROTOCOL_SEP = "://";
 
   private int sampleSize = 3;
 
@@ -70,6 +75,12 @@ class ExperimentalStateTracker {
   private final Map<String, Long> actionNanoStartTimes;
   private final Map<String, String> actionStrategy;
 
+  // running downloads are identified by the original URL they were trying to
+  // access.
+  private final Deque<String> runningDownloads;
+  private final Map<String, Long> downloadNanoStartTimes;
+  private final Map<String, DownloadProgressEvent> downloads;
+
   // For each test, the list of actions (again identified by the path of the
   // primary output) currently running for that test (identified by its label),
   // in order they got started. A key is present in the map if and only if that
@@ -92,6 +103,9 @@ class ExperimentalStateTracker {
     this.actionNanoStartTimes = new TreeMap<>();
     this.actionStrategy = new TreeMap<>();
     this.testActions = new TreeMap<>();
+    this.runningDownloads = new ArrayDeque<>();
+    this.downloads = new TreeMap<>();
+    this.downloadNanoStartTimes = new TreeMap<>();
     this.ok = true;
     this.clock = clock;
     this.targetWidth = targetWidth;
@@ -176,6 +190,25 @@ class ExperimentalStateTracker {
     buildComplete(event, "");
   }
 
+  synchronized void downloadProgress(DownloadProgressEvent event) {
+    String url = event.getOriginalUrl().toString();
+    if (event.isFinished()) {
+      // a download is finished, clean it up
+      runningDownloads.remove(url);
+      downloadNanoStartTimes.remove(url);
+      downloads.remove(url);
+    } else if (runningDownloads.contains(url)) {
+      // a new progress update on an already known, still running download
+      downloads.put(url, event);
+    } else {
+      // Start of a new download
+      long nanoTime = clock.nanoTime();
+      runningDownloads.add(url);
+      downloads.put(url, event);
+      downloadNanoStartTimes.put(url, nanoTime);
+    }
+  }
+
   synchronized void actionStarted(ActionStartedEvent event) {
     Action action = event.getAction();
     String name = action.getPrimaryOutput().getPath().getPathString();
@@ -410,11 +443,12 @@ class ExperimentalStateTracker {
         totalCount--;
         break;
       }
-      int width = (count >= sampleSize && count < actionCount) ? targetWidth - 8 : targetWidth - 4;
+      int width =
+          targetWidth - 4 - ((count >= sampleSize && count < actionCount) ? AND_MORE.length() : 0);
       terminalWriter.newline().append("    " + describeAction(action, nanoTime, width, toSkip));
     }
     if (totalCount < actionCount) {
-      terminalWriter.append(" ...");
+      terminalWriter.append(AND_MORE);
     }
   }
 
@@ -446,6 +480,9 @@ class ExperimentalStateTracker {
     if (packageProgressReceiver != null) {
       return true;
     }
+    if (runningDownloads.size() >= 1) {
+      return true;
+    }
     if (status != null) {
       return false;
     }
@@ -484,6 +521,90 @@ class ExperimentalStateTracker {
     }
   }
 
+  private String shortenUrl(String url, int width) {
+
+    if (url.length() < width) {
+      return url;
+    }
+
+    // Try to shorten to the form prot://host/.../rest/path/filename
+    String prefix = "";
+    int protocolIndex = url.indexOf(URL_PROTOCOL_SEP);
+    if (protocolIndex > 0) {
+      prefix = url.substring(0, protocolIndex + URL_PROTOCOL_SEP.length() + 1);
+      url = url.substring(protocolIndex + URL_PROTOCOL_SEP.length() + 1);
+      int hostIndex = url.indexOf("/");
+      if (hostIndex > 0) {
+        prefix = prefix + url.substring(0, hostIndex + 1);
+        url = url.substring(hostIndex + 1);
+        int targetLength = width - prefix.length();
+        // accept this form of shortening, if what is left from the filename is
+        // significantly longer (twice as long) as the ellipsis symbol introduced
+        if (targetLength > 3 * ELLIPSIS.length()) {
+          String shortPath = suffix(url, targetLength - ELLIPSIS.length());
+          int slashPos = shortPath.indexOf("/");
+          if (slashPos >= 0) {
+            return prefix + ELLIPSIS + shortPath.substring(slashPos);
+          } else {
+            return prefix + ELLIPSIS + shortPath;
+          }
+        }
+      }
+    }
+
+    // Last resort: just take a suffix
+    if (width <= ELLIPSIS.length()) {
+      // No chance to shorten anyway
+      return "";
+    }
+    return ELLIPSIS + suffix(url, width - ELLIPSIS.length());
+  }
+
+  private void reportOnOneDownload(
+      String url, long nanoTime, int width, AnsiTerminalWriter terminalWriter) throws IOException {
+
+    String postfix = "";
+
+    DownloadProgressEvent download = downloads.get(url);
+    long nanoDownloadTime = nanoTime - downloadNanoStartTimes.get(url);
+    long downloadSeconds = nanoDownloadTime / NANOS_PER_SECOND;
+
+    if (download.getBytesRead() > 0) {
+      postfix = postfix + " " + download.getBytesRead() + "b";
+    }
+    if (downloadSeconds > SHOW_TIME_THRESHOLD_SECONDS) {
+      postfix = postfix + " " + downloadSeconds + "s";
+    }
+    if (postfix.length() > 0) {
+      postfix = ";" + postfix;
+    }
+    url = shortenUrl(url, width - postfix.length());
+    terminalWriter.append(url + postfix);
+  }
+
+  private void reportOnDownloads(AnsiTerminalWriter terminalWriter) throws IOException {
+    int count = 0;
+    long nanoTime = clock.nanoTime();
+    int downloadCount = runningDownloads.size();
+    for (String url : runningDownloads) {
+      if (count >= sampleSize) {
+        break;
+      }
+      count++;
+      terminalWriter.newline().append(FETCH_PREFIX);
+      reportOnOneDownload(
+          url,
+          nanoTime,
+          targetWidth
+              - FETCH_PREFIX.length()
+              - ((count >= sampleSize && count < downloadCount) ? AND_MORE.length() : 0),
+          terminalWriter);
+    }
+    if (count < downloadCount) {
+      terminalWriter.append(AND_MORE);
+    }
+  }
+
   synchronized void writeProgressBar(AnsiTerminalWriter rawTerminalWriter, boolean shortVersion)
       throws IOException {
     PositionAwareAnsiTerminalWriter terminalWriter =
@@ -502,6 +623,9 @@ class ExperimentalStateTracker {
           terminalWriter.newline().append("    " + progress.getSecond());
         }
       }
+      if (!shortVersion) {
+        reportOnDownloads(terminalWriter);
+      }
       return;
     }
     if (packageProgressReceiver != null) {
@@ -510,6 +634,9 @@ class ExperimentalStateTracker {
       if (progress.getSecond().length() > 0) {
         terminalWriter.newline().append("    " + progress.getSecond());
       }
+      if (!shortVersion) {
+        reportOnDownloads(terminalWriter);
+      }
       return;
     }
     if (executionProgressReceiver != null) {
diff --git a/src/test/java/com/google/devtools/build/lib/BUILD b/src/test/java/com/google/devtools/build/lib/BUILD
index bcf79d61a6..b1bbf23d64 100644
--- a/src/test/java/com/google/devtools/build/lib/BUILD
+++ b/src/test/java/com/google/devtools/build/lib/BUILD
@@ -1068,6 +1068,7 @@ java_test(
         "//src/main/java/com/google/devtools/build/lib:util",
         "//src/main/java/com/google/devtools/build/lib:vfs",
         "//src/main/java/com/google/devtools/build/lib/actions",
+        "//src/main/java/com/google/devtools/build/lib/bazel/repository/downloader",
         "//src/main/java/com/google/devtools/build/lib/buildeventstream/proto:build_event_stream_java_proto",
         "//src/main/java/com/google/devtools/build/lib/buildeventstream/transports",
         "//src/main/java/com/google/devtools/common/options",
diff --git a/src/test/java/com/google/devtools/build/lib/runtime/ExperimentalStateTrackerTest.java b/src/test/java/com/google/devtools/build/lib/runtime/ExperimentalStateTrackerTest.java
index 7d47a8d162..954710e331 100644
--- a/src/test/java/com/google/devtools/build/lib/runtime/ExperimentalStateTrackerTest.java
+++ b/src/test/java/com/google/devtools/build/lib/runtime/ExperimentalStateTrackerTest.java
@@ -29,6 +29,7 @@ import com.google.devtools.build.lib.actions.ActionStatusMessage;
 import com.google.devtools.build.lib.actions.Artifact;
 import com.google.devtools.build.lib.actions.Root;
 import com.google.devtools.build.lib.analysis.ConfiguredTarget;
+import com.google.devtools.build.lib.bazel.repository.downloader.DownloadProgressEvent;
 import com.google.devtools.build.lib.buildtool.buildevent.TestFilteringCompleteEvent;
 import com.google.devtools.build.lib.cmdline.Label;
 import com.google.devtools.build.lib.packages.AspectDescriptor;
@@ -42,6 +43,7 @@ import com.google.devtools.build.lib.vfs.Path;
 import com.google.devtools.build.lib.vfs.PathFragment;
 import com.google.devtools.build.lib.view.test.TestStatus.BlazeTestStatus;
 import java.io.IOException;
+import java.net.URL;
 import java.util.concurrent.TimeUnit;
 import org.junit.Test;
 import org.junit.runner.RunWith;
@@ -576,4 +578,91 @@ public class ExperimentalStateTrackerTest extends FoundationTestCase {
     assertEquals("", ExperimentalStateTracker.suffix("foo", -2));
     assertEquals("foobar", ExperimentalStateTracker.suffix("foobar", 200));
   }
+
+  @Test
+  public void testDownloadShown() throws Exception {
+    // Verify that, whenever a single download is running in loading face, it is shown in the status
+    // bar.
+    ManualClock clock = new ManualClock();
+    clock.advanceMillis(TimeUnit.SECONDS.toMillis(1234));
+    ExperimentalStateTracker stateTracker = new ExperimentalStateTracker(clock, 80);
+
+    URL url = new URL("http://example.org/first/dep");
+
+    stateTracker.buildStarted(null);
+    stateTracker.downloadProgress(new DownloadProgressEvent(url));
+    clock.advanceMillis(TimeUnit.SECONDS.toMillis(6));
+
+    LoggingTerminalWriter terminalWriter = new LoggingTerminalWriter(/*discardHighlight=*/ true);
+    stateTracker.writeProgressBar(terminalWriter);
+    String output = terminalWriter.getTranscript();
+
+    assertTrue(
+        "Progress bar should contain '" + url.toString() + "', but was:\n" + output,
+        output.contains(url.toString()));
+    assertTrue("Progress bar should contain '6s', but was:\n" + output, output.contains("6s"));
+
+    // Progress on the pending download should be reported appropriately
+    clock.advanceMillis(TimeUnit.SECONDS.toMillis(1));
+    stateTracker.downloadProgress(new DownloadProgressEvent(url, 256));
+
+    terminalWriter = new LoggingTerminalWriter(/*discardHighlight=*/ true);
+    stateTracker.writeProgressBar(terminalWriter);
+    output = terminalWriter.getTranscript();
+
+    assertTrue(
+        "Progress bar should contain '" + url.toString() + "', but was:\n" + output,
+        output.contains(url.toString()));
+    assertTrue("Progress bar should contain '7s', but was:\n" + output, output.contains("7s"));
+    assertTrue("Progress bar should contain '256', but was:\n" + output, output.contains("256"));
+
+    // After finishing the download, it should no longer be reported.
+    clock.advanceMillis(TimeUnit.SECONDS.toMillis(1));
+    stateTracker.downloadProgress(new DownloadProgressEvent(url, 256, true));
+
+    terminalWriter = new LoggingTerminalWriter(/*discardHighlight=*/ true);
+    stateTracker.writeProgressBar(terminalWriter);
+    output = terminalWriter.getTranscript();
+
+    assertFalse(
+        "Progress bar should not contain url, but was:\n" + output, output.contains("example.org"));
+  }
+
+  @Test
+  public void testDownloadOutputLength() throws Exception {
+    // Verify that URLs are shortened in a reasonable way, if the terminal is not wide enough
+    // Also verify that the length is respected, even if only a download sample is shown.
+    ManualClock clock = new ManualClock();
+    clock.advanceMillis(TimeUnit.SECONDS.toMillis(1234));
+    ExperimentalStateTracker stateTracker = new ExperimentalStateTracker(clock, 60);
+    URL url = new URL("http://example.org/some/really/very/very/long/path/filename.tar.gz");
+
+    stateTracker.buildStarted(null);
+    stateTracker.downloadProgress(new DownloadProgressEvent(url));
+    clock.advanceMillis(TimeUnit.SECONDS.toMillis(6));
+    for (int i = 0; i < 10; i++) {
+      stateTracker.downloadProgress(
+          new DownloadProgressEvent(
+              new URL(
+                  "http://otherhost.example/another/also/length/path/to/another/download"
+                      + i
+                      + ".zip")));
+      clock.advanceMillis(TimeUnit.SECONDS.toMillis(1));
+    }
+
+    LoggingTerminalWriter terminalWriter = new LoggingTerminalWriter(/*discardHighlight=*/ true);
+    stateTracker.writeProgressBar(terminalWriter);
+    String output = terminalWriter.getTranscript();
+
+    assertTrue(
+        "Only lines with at most 60 chars should be present in the output:\n" + output,
+        longestLine(output) <= 60);
+    assertTrue(
+        "Output still should contain the filename, but was:\n" + output,
+        output.contains("filename.tar.gz"));
+    assertTrue(
+        "Output still should contain the host name, but was:\n" + output,
+        output.contains("example.org"));
+  }
+
 }