Improve progress indicator

9 files changed, 45 insertions, 51 deletions

diff --git a/src/libstore/build.cc b/src/libstore/build.cc
index 91156d313e2e..44cae3431fc2 100644
--- a/src/libstore/build.cc
+++ b/src/libstore/build.cc
@@ -120,6 +120,8 @@ protected:
     /* Whether the goal is finished. */
     ExitCode exitCode;
 
+    Activity act;
+
     Goal(Worker & worker) : worker(worker)
     {
         nrFailed = nrNoSubstituters = nrIncompleteClosure = 0;
@@ -168,7 +170,8 @@ public:
     virtual string key() = 0;
 
 protected:
-    void amDone(ExitCode result);
+
+    virtual void amDone(ExitCode result);
 };
 
 
@@ -902,6 +905,12 @@ private:
 
     void repairClosure();
 
+    void amDone(ExitCode result)
+    {
+        logger->event(evBuildFinished, act, result == ecSuccess);
+        Goal::amDone(result);
+    }
+
     void done(BuildResult::Status status, const string & msg = "");
 };
 
@@ -920,6 +929,8 @@ DerivationGoal::DerivationGoal(const Path & drvPath, const StringSet & wantedOut
     state = &DerivationGoal::getDerivation;
     name = (format("building of ‘%1%’") % drvPath).str();
     trace("created");
+
+    logger->event(evBuildCreated, act, drvPath);
 }
 
 
@@ -935,6 +946,8 @@ DerivationGoal::DerivationGoal(const Path & drvPath, const BasicDerivation & drv
     name = (format("building of %1%") % showPaths(drv.outputPaths())).str();
     trace("created");
 
+    logger->event(evBuildCreated, act, drvPath);
+
     /* Prevent the .chroot directory from being
        garbage-collected. (See isActiveTempFile() in gc.cc.) */
     worker.store.addTempRoot(drvPath);
@@ -2112,6 +2125,8 @@ void DerivationGoal::startBuilder()
         }
         debug(msg);
     }
+
+    logger->event(evBuildStarted, act);
 }
 
 
@@ -2857,7 +2872,7 @@ void DerivationGoal::registerOutputs()
            contained in it.  Compute the SHA-256 NAR hash at the same
            time.  The hash is stored in the database so that we can
            verify later on whether nobody has messed with the store. */
-        Activity act(*logger, lvlTalkative, format("scanning for references inside ‘%1%’") % path);
+        debug("scanning for references inside ‘%1%’", path);
         HashResult hash;
         PathSet references = scanForReferences(actualPath, allPaths, hash);
 
@@ -3130,6 +3145,7 @@ void DerivationGoal::flushLine()
         logTail.push_back(currentLogLine);
         if (logTail.size() > settings.logLines) logTail.pop_front();
     }
+    logger->event(evBuildOutput, act, currentLogLine);
     currentLogLine = "";
     currentLogLinePos = 0;
 }
@@ -3244,6 +3260,12 @@ public:
     void handleEOF(int fd);
 
     Path getStorePath() { return storePath; }
+
+    void amDone(ExitCode result)
+    {
+        logger->event(evSubstitutionFinished, act, result == ecSuccess);
+        Goal::amDone(result);
+    }
 };
 
 
@@ -3256,6 +3278,7 @@ SubstitutionGoal::SubstitutionGoal(const Path & storePath, Worker & worker, bool
     state = &SubstitutionGoal::init;
     name = (format("substitution of ‘%1%’") % storePath).str();
     trace("created");
+    logger->event(evSubstitutionCreated, act, storePath);
 }
 
 
@@ -3391,6 +3414,8 @@ void SubstitutionGoal::tryToRun()
 
     printInfo(format("fetching path ‘%1%’...") % storePath);
 
+    logger->event(evSubstitutionStarted, act);
+
     outPipe.create();
 
     promise = std::promise<void>();
@@ -3637,7 +3662,7 @@ void Worker::run(const Goals & _topGoals)
 {
     for (auto & i : _topGoals) topGoals.insert(i);
 
-    Activity act(*logger, lvlDebug, "entered goal loop");
+    debug("entered goal loop");
 
     while (1) {
 
diff --git a/src/libstore/builtins.cc b/src/libstore/builtins.cc
index c5dbd57f8bc6..8a5cf3327d44 100644
--- a/src/libstore/builtins.cc
+++ b/src/libstore/builtins.cc
@@ -28,9 +28,6 @@ void builtinFetchurl(const BasicDerivation & drv, const std::string & netrcData)
         DownloadRequest request(url);
         request.verifyTLS = false;
 
-        /* Show a progress indicator, even though stderr is not a tty. */
-        request.showProgress = DownloadRequest::yes;
-
         /* Note: have to use a fresh downloader here because we're in
            a forked process. */
         auto data = makeDownloader()->download(request);
diff --git a/src/libstore/download.cc b/src/libstore/download.cc
index dc1a3d94f74f..63e498f0603a 100644
--- a/src/libstore/download.cc
+++ b/src/libstore/download.cc
@@ -63,6 +63,7 @@ struct CurlDownloader : public Downloader
         CurlDownloader & downloader;
         DownloadRequest request;
         DownloadResult result;
+        Activity act;
         bool done = false; // whether either the success or failure function has been called
         std::function<void(const DownloadResult &)> success;
         std::function<void(std::exception_ptr exc)> failure;
@@ -70,10 +71,6 @@ struct CurlDownloader : public Downloader
         bool active = false; // whether the handle has been added to the multi object
         std::string status;
 
-        bool showProgress = false;
-        double prevProgressTime{0}, startTime{0};
-        unsigned int moveBack{1};
-
         unsigned int attempt = 0;
 
         /* Don't start this download until the specified time point
@@ -87,12 +84,10 @@ struct CurlDownloader : public Downloader
         DownloadItem(CurlDownloader & downloader, const DownloadRequest & request)
             : downloader(downloader), request(request)
         {
-            showProgress =
-                request.showProgress == DownloadRequest::yes ||
-                (request.showProgress == DownloadRequest::automatic && isatty(STDERR_FILENO));
-
             if (!request.expectedETag.empty())
                 requestHeaders = curl_slist_append(requestHeaders, ("If-None-Match: " + request.expectedETag).c_str());
+
+            logger->event(evDownloadCreated, act, request.uri);
         }
 
         ~DownloadItem()
@@ -109,6 +104,7 @@ struct CurlDownloader : public Downloader
             } catch (...) {
                 ignoreException();
             }
+            logger->event(evDownloadDestroyed, act);
         }
 
         template<class T>
@@ -171,19 +167,7 @@ struct CurlDownloader : public Downloader
 
         int progressCallback(double dltotal, double dlnow)
         {
-            if (showProgress) {
-                double now = getTime();
-                if (prevProgressTime <= now - 1) {
-                    string s = (format(" [%1$.0f/%2$.0f KiB, %3$.1f KiB/s]")
-                        % (dlnow / 1024.0)
-                        % (dltotal / 1024.0)
-                        % (now == startTime ? 0 : dlnow / 1024.0 / (now - startTime))).str();
-                    std::cerr << "\e[" << moveBack << "D" << s;
-                    moveBack = s.size();
-                    std::cerr.flush();
-                    prevProgressTime = now;
-                }
-            }
+            logger->event(evDownloadProgress, act, dltotal, dlnow);
             return _isInterrupted;
         }
 
@@ -201,13 +185,6 @@ struct CurlDownloader : public Downloader
 
         void init()
         {
-            // FIXME: handle parallel downloads.
-            if (showProgress) {
-                std::cerr << (format("downloading ‘%1%’... ") % request.uri);
-                std::cerr.flush();
-                startTime = getTime();
-            }
-
             if (!req) req = curl_easy_init();
 
             curl_easy_reset(req);
@@ -263,10 +240,6 @@ struct CurlDownloader : public Downloader
 
         void finish(CURLcode code)
         {
-            if (showProgress)
-                //std::cerr << "\e[" << moveBack << "D\e[K\n";
-                std::cerr << "\n";
-
             long httpStatus = 0;
             curl_easy_getinfo(req, CURLINFO_RESPONSE_CODE, &httpStatus);
 
@@ -292,6 +265,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());
                 } catch (...) {
                     done = true;
                     callFailure(failure, std::current_exception());
diff --git a/src/libstore/download.hh b/src/libstore/download.hh
index 62f3860b9dae..7d8982d64c4c 100644
--- a/src/libstore/download.hh
+++ b/src/libstore/download.hh
@@ -13,7 +13,6 @@ struct DownloadRequest
     std::string uri;
     std::string expectedETag;
     bool verifyTLS = true;
-    enum { yes, no, automatic } showProgress = yes;
     bool head = false;
     size_t tries = 5;
     unsigned int baseRetryTimeMs = 250;
diff --git a/src/libstore/export-import.cc b/src/libstore/export-import.cc
index 2b8ab063e18e..6e8bc692cdff 100644
--- a/src/libstore/export-import.cc
+++ b/src/libstore/export-import.cc
@@ -30,13 +30,13 @@ void Store::exportPaths(const Paths & paths, Sink & sink)
     std::reverse(sorted.begin(), sorted.end());
 
     std::string doneLabel("paths exported");
-    logger->incExpected(doneLabel, sorted.size());
+    //logger->incExpected(doneLabel, sorted.size());
 
     for (auto & path : sorted) {
-        Activity act(*logger, lvlInfo, format("exporting path ‘%s’") % path);
+        //Activity act(*logger, lvlInfo, format("exporting path ‘%s’") % path);
         sink << 1;
         exportPath(path, sink);
-        logger->incProgress(doneLabel);
+        //logger->incProgress(doneLabel);
     }
 
     sink << 0;
@@ -81,7 +81,7 @@ Paths Store::importPaths(Source & source, std::shared_ptr<FSAccessor> accessor,
 
         info.path = readStorePath(*this, source);
 
-        Activity act(*logger, lvlInfo, format("importing path ‘%s’") % info.path);
+        //Activity act(*logger, lvlInfo, format("importing path ‘%s’") % info.path);
 
         info.references = readStorePaths<PathSet>(*this, source);
 
diff --git a/src/libstore/gc.cc b/src/libstore/gc.cc
index 3e7e42cbc969..3cdbb114a79d 100644
--- a/src/libstore/gc.cc
+++ b/src/libstore/gc.cc
@@ -615,7 +615,7 @@ void LocalStore::tryToDelete(GCState & state, const Path & path)
     auto realPath = realStoreDir + "/" + baseNameOf(path);
     if (realPath == linksDir || realPath == trashDir) return;
 
-    Activity act(*logger, lvlDebug, format("considering whether to delete ‘%1%’") % path);
+    //Activity act(*logger, lvlDebug, format("considering whether to delete ‘%1%’") % path);
 
     if (!isStorePath(path) || !isValidPath(path)) {
         /* A lock file belonging to a path that we're building right
diff --git a/src/libstore/http-binary-cache-store.cc b/src/libstore/http-binary-cache-store.cc
index 37a7d6ace142..cead81514ab4 100644
--- a/src/libstore/http-binary-cache-store.cc
+++ b/src/libstore/http-binary-cache-store.cc
@@ -50,7 +50,6 @@ protected:
     {
         try {
             DownloadRequest request(cacheUri + "/" + path);
-            request.showProgress = DownloadRequest::no;
             request.head = true;
             request.tries = 5;
             getDownloader()->download(request);
@@ -76,7 +75,6 @@ protected:
         std::function<void(std::exception_ptr exc)> failure) override
     {
         DownloadRequest request(cacheUri + "/" + path);
-        request.showProgress = DownloadRequest::no;
         request.tries = 8;
 
         getDownloader()->enqueueDownload(request,
diff --git a/src/libstore/optimise-store.cc b/src/libstore/optimise-store.cc
index d354812e3da4..56167c4dfae8 100644
--- a/src/libstore/optimise-store.cc
+++ b/src/libstore/optimise-store.cc
@@ -240,7 +240,7 @@ void LocalStore::optimiseStore(OptimiseStats & stats)
     for (auto & i : paths) {
         addTempRoot(i);
         if (!isValidPath(i)) continue; /* path was GC'ed, probably */
-        Activity act(*logger, lvlChatty, format("hashing files in ‘%1%’") % i);
+        //Activity act(*logger, lvlChatty, format("hashing files in ‘%1%’") % i);
         optimisePath_(stats, realStoreDir + "/" + baseNameOf(i), inodeHash);
     }
 }
diff --git a/src/libstore/store-api.cc b/src/libstore/store-api.cc
index 96799adb1e63..e6cbd53dc80a 100644
--- a/src/libstore/store-api.cc
+++ b/src/libstore/store-api.cc
@@ -822,7 +822,7 @@ void copyPaths(ref<Store> from, ref<Store> to, const PathSet & storePaths,
 
     std::string copiedLabel = "copied";
 
-    logger->setExpected(copiedLabel, missing.size());
+    //logger->setExpected(copiedLabel, missing.size());
 
     ThreadPool pool;
 
@@ -838,13 +838,14 @@ void copyPaths(ref<Store> from, ref<Store> to, const PathSet & storePaths,
             checkInterrupt();
 
             if (!to->isValidPath(storePath)) {
-                Activity act(*logger, lvlInfo, format("copying ‘%s’...") % storePath);
+                //Activity act(*logger, lvlInfo, format("copying ‘%s’...") % storePath);
 
                 copyStorePath(from, to, storePath, false, dontCheckSigs);
 
-                logger->incProgress(copiedLabel);
+                //logger->incProgress(copiedLabel);
             } else
-                logger->incExpected(copiedLabel, -1);
+                ;
+                //logger->incExpected(copiedLabel, -1);
         });
 
     pool.process();