Improve substitution progress indicator

E.g.

  $ nix build --store local?root=/tmp/nix nixpkgs.firefox-unwrapped
  [0/1 built, 1/97/98 fetched, 65.8/92.8 MiB DL, 203.2/309.2 MiB copied] downloading 'https://cache.nixos.org/nar/1czm9fk0svacy4h6a3fzkpafi4f7a9gml36kk8cq1igaghbspg3k.nar.xz'

src/libstore/build.cc

@@ -9,6 +9,7 @@
 #include "finally.hh"
 #include "compression.hh"
 #include "json.hh"
+#include "nar-info.hh"
 
 #include <algorithm>
 #include <iostream>
@@ -201,6 +202,16 @@ struct Child
 };
 
 
+template<typename T>
+struct MaintainCount
+{
+    T & counter;
+    T delta;
+    MaintainCount(T & counter, T delta) : counter(counter), delta(delta) { counter += delta; }
+    ~MaintainCount() { counter -= delta; }
+};
+
+
 /* The worker class. */
 class Worker
 {
@@ -244,6 +255,8 @@ private:
 
 public:
 
+    const Activity act;
+
     /* Set if at least one derivation had a BuildError (i.e. permanent
        failure). */
     bool permanentFailure;
@@ -255,6 +268,11 @@ public:
 
     std::unique_ptr<HookInstance> hook;
 
+    uint64_t expectedDownloadSize = 0;
+    uint64_t doneDownloadSize = 0;
+    uint64_t expectedNarSize = 0;
+    uint64_t doneNarSize = 0;
+
     Worker(LocalStore & store);
     ~Worker();
 
@@ -313,6 +331,12 @@ public:
     bool pathContentsGood(const Path & path);
 
     void markContentsGood(const Path & path);
+
+    void updateProgress()
+    {
+        logger->event(evSetExpected, act, actDownload, expectedDownloadSize + doneDownloadSize);
+        logger->event(evSetExpected, act, actCopyPath, expectedNarSize + doneNarSize);
+    }
 };
 
 
@@ -3304,6 +3328,8 @@ private:
        storePath when doing a repair. */
     Path destPath;
 
+    std::unique_ptr<MaintainCount<uint64_t>> maintainExpectedNar, maintainExpectedDownload;
+
     typedef void (SubstitutionGoal::*GoalState)();
     GoalState state;
 
@@ -3430,6 +3456,18 @@ void SubstitutionGoal::tryNext()
         return;
     }
 
+    /* Update the total expected download size. */
+    auto narInfo = std::dynamic_pointer_cast<const NarInfo>(info);
+
+    maintainExpectedNar = std::make_unique<MaintainCount<uint64_t>>(worker.expectedNarSize, narInfo->narSize);
+
+    maintainExpectedDownload =
+        narInfo && narInfo->fileSize
+        ? std::make_unique<MaintainCount<uint64_t>>(worker.expectedDownloadSize, narInfo->fileSize)
+        : nullptr;
+
+    worker.updateProgress();
+
     hasSubstitute = true;
 
     /* Bail out early if this substituter lacks a valid
@@ -3538,6 +3576,17 @@ void SubstitutionGoal::finished()
     printMsg(lvlChatty,
         format("substitution of path '%1%' succeeded") % storePath);
 
+    if (maintainExpectedDownload) {
+        auto fileSize = maintainExpectedDownload->delta;
+        maintainExpectedDownload.reset();
+        worker.doneDownloadSize += fileSize;
+    }
+
+    worker.doneNarSize += maintainExpectedNar->delta;
+    maintainExpectedNar.reset();
+
+    worker.updateProgress();
+
     amDone(ecSuccess);
 }
 
@@ -3560,7 +3609,8 @@ static bool working = false;
 
 
 Worker::Worker(LocalStore & store)
-    : store(store)
+    : act(actRealise)
+    , store(store)
 {
     /* Debugging: prevent recursive workers. */
     if (working) abort();
@@ -3581,6 +3631,9 @@ Worker::~Worker()
        are in trouble, since goals may call childTerminated() etc. in
        their destructors). */
     topGoals.clear();
+
+    assert(expectedDownloadSize == 0);
+    assert(expectedNarSize == 0);
 }
 
 

src/libstore/download.cc

@@ -83,12 +83,12 @@ struct CurlDownloader : public Downloader
         std::string encoding;
 
         DownloadItem(CurlDownloader & downloader, const DownloadRequest & request)
-            : downloader(downloader), request(request)
+            : downloader(downloader)
+            , request(request)
+            , act(actDownload, fmt("downloading '%s'", request.uri))
         {
             if (!request.expectedETag.empty())
                 requestHeaders = curl_slist_append(requestHeaders, ("If-None-Match: " + request.expectedETag).c_str());
-
-            logger->event(evDownloadCreated, act, request.uri);
         }
 
         ~DownloadItem()
@@ -105,7 +105,6 @@ struct CurlDownloader : public Downloader
             } catch (...) {
                 ignoreException();
             }
-            logger->event(evDownloadDestroyed, act);
         }
 
         template<class T>
@@ -168,7 +167,7 @@ struct CurlDownloader : public Downloader
 
         int progressCallback(double dltotal, double dlnow)
         {
-            logger->event(evDownloadProgress, act, dltotal, dlnow);
+            act.progress(dlnow, dltotal);
             return _isInterrupted;
         }
 
@@ -267,7 +266,7 @@ struct CurlDownloader : public Downloader
                 try {
                     result.data = decodeContent(encoding, ref<std::string>(result.data));
                     callSuccess(success, failure, const_cast<const DownloadResult &>(result));
-                    logger->event(evDownloadSucceeded, act, result.data->size());
+                    act.progress(result.data->size(), result.data->size());
                 } catch (...) {
                     done = true;
                     callFailure(failure, std::current_exception());

src/libutil/logging.hh

@@ -16,6 +16,8 @@ typedef enum {
 typedef enum {
     actUnknown = 0,
     actCopyPath = 100,
+    actDownload = 101,
+    actRealise = 102,
 } ActivityType;
 
 class Activity
@@ -38,10 +40,6 @@ typedef enum {
     evBuildStarted = 1,
     evBuildOutput = 2,
     evBuildFinished = 3,
-    evDownloadCreated = 4,
-    evDownloadDestroyed = 5,
-    evDownloadProgress = 6,
-    evDownloadSucceeded = 7,
     evSubstitutionCreated = 8,
     evSubstitutionStarted = 9,
     evSubstitutionFinished = 10,

src/nix/installables.cc

@@ -229,7 +229,7 @@ std::vector<std::shared_ptr<Installable>> InstallablesCommand::parseInstallables
 
 PathSet InstallablesCommand::toStorePaths(ref<Store> store, ToStorePathsMode mode)
 {
-    if (mode != DryRun)
+    if (mode != Build)
         settings.readOnlyMode = true;
 
     PathSet outPaths, buildables;

src/nix/progress-bar.cc

@@ -25,14 +25,6 @@ private:
         std::map<ActivityType, uint64_t> expectedByType;
     };
 
-    struct DownloadInfo
-    {
-        std::string uri;
-        uint64_t current = 0;
-        uint64_t expected = 0;
-        DownloadInfo(const std::string & uri) : uri(uri) { }
-    };
-
     struct CopyInfo
     {
         uint64_t expected = 0;
@@ -58,9 +50,6 @@ private:
         std::set<Activity::t> runningSubstitutions;
         uint64_t succeededSubstitutions = 0;
 
-        uint64_t downloadedBytes = 0; // finished downloads
-        std::map<Activity::t, DownloadInfo> downloads;
-
         std::map<Activity::t, CopyInfo> runningCopies;
 
         std::list<ActInfo> activities;
@@ -155,12 +144,18 @@ public:
         if (!state.activities.empty()) {
             if (!status.empty()) line += " ";
             auto i = state.activities.rbegin();
+
+            while (i != state.activities.rend() && i->s.empty() && i->s2.empty())
+                ++i;
+
+            if (i != state.activities.rend()) {
                 line += i->s;
                 if (!i->s2.empty()) {
                     line += ": ";
                     line += i->s2;
                 }
             }
+        }
 
         line += "\e[K";
         writeToStderr(std::string(line, 0, width - 1));
@@ -172,9 +167,13 @@ public:
 
         std::string res;
 
-        if (state.failedBuilds) {
+        auto add = [&](const std::string & s) {
             if (!res.empty()) res += ", ";
-            res += fmt(ANSI_RED "%d failed" ANSI_NORMAL, state.failedBuilds);
+            res += s;
+        };
+
+        if (state.failedBuilds) {
+            add(fmt(ANSI_RED "%d failed" ANSI_NORMAL, state.failedBuilds));
         }
 
         if (!state.builds.empty() || state.succeededBuilds)
@@ -195,27 +194,17 @@ public:
                 state.succeededSubstitutions + state.substitutions.size());
         }
 
-        if (!state.downloads.empty() || state.downloadedBytes) {
-            if (!res.empty()) res += ", ";
-            uint64_t expected = state.downloadedBytes, current = state.downloadedBytes;
-            for (auto & i : state.downloads) {
-                expected += i.second.expected;
-                current += i.second.current;
-            }
-            res += fmt("%1$.0f/%2$.0f KiB", current / 1024.0, expected / 1024.0);
-        }
-
         if (!state.runningCopies.empty()) {
-            if (!res.empty()) res += ", ";
             uint64_t copied = 0, expected = 0;
             for (auto & i : state.runningCopies) {
                 copied += i.second.copied;
                 expected += i.second.expected - (i.second.done - i.second.copied);
             }
-            res += fmt("%d/%d copied", copied, expected);
+            add(fmt("%d/%d copied", copied, expected));
         }
 
-        auto & act = state.activitiesByType[actCopyPath];
+        auto showActivity = [&](ActivityType type, const std::string & f) {
+            auto & act = state.activitiesByType[type];
             uint64_t done = act.done, expected = act.done;
             for (auto & j : act.its) {
                 done += j.second->done;
@@ -224,10 +213,12 @@ public:
 
             expected = std::max(expected, act.expected);
 
-        if (done || expected) {
-            if (!res.empty()) res += ", ";
-            res += fmt("%1$.1f/%2$.1f MiB copied", done / MiB, expected / MiB);
-        }
+            if (done || expected)
+                add(fmt(f, done / MiB, expected / MiB));
+        };
+
+        showActivity(actDownload, "%1$.1f/%2$.1f MiB DL");
+        showActivity(actCopyPath, "%1$.1f/%2$.1f MiB copied");
 
         return res;
     }
@@ -318,40 +309,6 @@ public:
             deleteActivity(*state, act);
         }
 
-        if (ev.type == evDownloadCreated) {
-            Activity::t act = ev.getI(0);
-            std::string uri = ev.getS(1);
-            state->downloads.emplace(act, DownloadInfo{uri});
-            if (state->runningSubstitutions.empty()) // FIXME: hack
-                createActivity(*state, act, fmt("downloading " ANSI_BOLD "%s" ANSI_NORMAL "", uri));
-        }
-
-        if (ev.type == evDownloadProgress) {
-            Activity::t act = ev.getI(0);
-            auto i = state->downloads.find(act);
-            assert(i != state->downloads.end());
-            i->second.expected = ev.getI(1);
-            i->second.current = ev.getI(2);
-        }
-
-        if (ev.type == evDownloadSucceeded) {
-            Activity::t act = ev.getI(0);
-            auto i = state->downloads.find(act);
-            assert(i != state->downloads.end());
-            state->downloadedBytes += ev.getI(1);
-            state->downloads.erase(i);
-            deleteActivity(*state, act);
-        }
-
-        if (ev.type == evDownloadDestroyed) {
-            Activity::t act = ev.getI(0);
-            auto i = state->downloads.find(act);
-            if (i != state->downloads.end()) {
-                state->downloads.erase(i);
-                deleteActivity(*state, act);
-            }
-        }
-
         if (ev.type == evCopyProgress) {
             Activity::t act = ev.getI(0);
             auto & i = state->runningCopies[act];