Improve progress indicator

26 files changed, 339 insertions, 168 deletions

diff --git a/src/libexpr/eval.cc b/src/libexpr/eval.cc
index 5e1ae63c4..0cdce602d 100644
--- a/src/libexpr/eval.cc
+++ b/src/libexpr/eval.cc
@@ -642,7 +642,7 @@ void EvalState::evalFile(const Path & path, Value & v)
         return;
     }
 
-    Activity act(*logger, lvlTalkative, format("evaluating file ‘%1%’") % path2);
+    printTalkative("evaluating file ‘%1%’", path2);
     Expr * e = parseExprFromFile(checkSourcePath(path2));
     try {
         eval(e, v);
diff --git a/src/libexpr/get-drvs.cc b/src/libexpr/get-drvs.cc
index ae9fb0e5e..4200e8fd6 100644
--- a/src/libexpr/get-drvs.cc
+++ b/src/libexpr/get-drvs.cc
@@ -289,7 +289,7 @@ static void getDerivations(EvalState & state, Value & vIn,
            bound to the attribute with the "lower" name should take
            precedence). */
         for (auto & i : v.attrs->lexicographicOrder()) {
-            Activity act(*logger, lvlDebug, format("evaluating attribute ‘%1%’") % i->name);
+            debug("evaluating attribute ‘%1%’", i->name);
             if (!std::regex_match(std::string(i->name), attrRegex))
                 continue;
             string pathPrefix2 = addToPath(pathPrefix, i->name);
@@ -310,7 +310,6 @@ static void getDerivations(EvalState & state, Value & vIn,
 
     else if (v.isList()) {
         for (unsigned int n = 0; n < v.listSize(); ++n) {
-            Activity act(*logger, lvlDebug, "evaluating list element");
             string pathPrefix2 = addToPath(pathPrefix, (format("%1%") % n).str());
             if (getDerivation(state, *v.listElems()[n], pathPrefix2, drvs, done, ignoreAssertionFailures))
                 getDerivations(state, *v.listElems()[n], pathPrefix2, autoArgs, drvs, done, ignoreAssertionFailures);
diff --git a/src/libexpr/primops.cc b/src/libexpr/primops.cc
index cc23827a1..93b66269d 100644
--- a/src/libexpr/primops.cc
+++ b/src/libexpr/primops.cc
@@ -127,7 +127,7 @@ static void prim_scopedImport(EvalState & state, const Pos & pos, Value * * args
                 env->values[displ++] = attr.value;
             }
 
-            Activity act(*logger, lvlTalkative, format("evaluating file ‘%1%’") % path);
+            printTalkative("evaluating file ‘%1%’", path);
             Expr * e = state.parseExprFromFile(resolveExprPath(path), staticEnv);
 
             e->eval(state, *env, v);
@@ -326,8 +326,6 @@ typedef list<Value *> ValueList;
 
 static void prim_genericClosure(EvalState & state, const Pos & pos, Value * * args, Value & v)
 {
-    Activity act(*logger, lvlDebug, "finding dependencies");
-
     state.forceAttrs(*args[0], pos);
 
     /* Get the start set. */
@@ -499,8 +497,6 @@ void prim_valueSize(EvalState & state, const Pos & pos, Value * * args, Value &
    derivation. */
 static void prim_derivationStrict(EvalState & state, const Pos & pos, Value * * args, Value & v)
 {
-    Activity act(*logger, lvlVomit, "evaluating derivation");
-
     state.forceAttrs(*args[0], pos);
 
     /* Figure out the name first (for stack backtraces). */
@@ -544,7 +540,7 @@ static void prim_derivationStrict(EvalState & state, const Pos & pos, Value * *
     for (auto & i : args[0]->attrs->lexicographicOrder()) {
         if (i->name == state.sIgnoreNulls) continue;
         string key = i->name;
-        Activity act(*logger, lvlVomit, format("processing attribute ‘%1%’") % key);
+        vomit("processing attribute ‘%1%’", key);
 
         auto handleHashMode = [&](const std::string & s) {
             if (s == "recursive") outputHashRecursive = true;
diff --git a/src/libexpr/primops/fetchgit.cc b/src/libexpr/primops/fetchgit.cc
index 09e2c077b..3e4ece2cf 100644
--- a/src/libexpr/primops/fetchgit.cc
+++ b/src/libexpr/primops/fetchgit.cc
@@ -17,7 +17,7 @@ Path exportGit(ref<Store> store, const std::string & uri, const std::string & re
         runProgram("git", true, { "init", "--bare", cacheDir });
     }
 
-    Activity act(*logger, lvlInfo, format("fetching Git repository ‘%s’") % uri);
+    //Activity act(*logger, lvlInfo, format("fetching Git repository ‘%s’") % uri);
 
     std::string localRef = "pid-" + std::to_string(getpid());
     Path localRefFile = cacheDir + "/refs/heads/" + localRef;
diff --git a/src/libstore/build.cc b/src/libstore/build.cc
index 91156d313..44cae3431 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 c5dbd57f8..8a5cf3327 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 dc1a3d94f..63e498f06 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 62f3860b9..7d8982d64 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 2b8ab063e..6e8bc692c 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 3e7e42cbc..3cdbb114a 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 37a7d6ace..cead81514 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 d354812e3..56167c4df 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 96799adb1..e6cbd53dc 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();
diff --git a/src/libutil/logging.cc b/src/libutil/logging.cc
index afcc2ec58..2d0acca24 100644
--- a/src/libutil/logging.cc
+++ b/src/libutil/logging.cc
@@ -1,6 +1,8 @@
 #include "logging.hh"
 #include "util.hh"
 
+#include <atomic>
+
 namespace nix {
 
 Logger * logger = makeDefaultLogger();
@@ -42,12 +44,7 @@ public:
         writeToStderr(prefix + (tty ? fs.s : filterANSIEscapes(fs.s)) + "\n");
     }
 
-    void startActivity(Activity & activity, Verbosity lvl, const FormatOrString & fs) override
-    {
-        log(lvl, fs);
-    }
-
-    void stopActivity(Activity & activity) override
+    void event(const Event & ev) override
     {
     }
 };
@@ -79,4 +76,8 @@ Logger * makeDefaultLogger()
     return new SimpleLogger();
 }
 
+std::atomic<uint64_t> Activity::nextId{(uint64_t) getpid() << 32};
+
+Activity::Activity() : id(nextId++) { };
+
 }
diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh
index a8c69dbd9..ddfc336fe 100644
--- a/src/libutil/logging.hh
+++ b/src/libutil/logging.hh
@@ -13,7 +13,64 @@ typedef enum {
     lvlVomit
 } Verbosity;
 
-class Activity;
+class Activity
+{
+    static std::atomic<uint64_t> nextId;
+public:
+    typedef uint64_t t;
+    const t id;
+    Activity();
+    Activity(const Activity & act) : id(act.id) { };
+    Activity(uint64_t id) : id(id) { };
+};
+
+typedef enum {
+    evBuildCreated = 0,
+    evBuildStarted = 1,
+    evBuildOutput = 2,
+    evBuildFinished = 3,
+    evDownloadCreated = 4,
+    evDownloadDestroyed = 5,
+    evDownloadProgress = 6,
+    evDownloadSucceeded = 7,
+    evSubstitutionCreated = 8,
+    evSubstitutionStarted = 9,
+    evSubstitutionFinished = 10,
+} EventType;
+
+struct Event
+{
+    struct Field
+    {
+        // FIXME: use std::variant.
+        enum { tInt, tString } type;
+        uint64_t i = 0;
+        std::string s;
+        Field(const std::string & s) : type(tString), s(s) { }
+        Field(const char * s) : type(tString), s(s) { }
+        Field(const uint64_t & i) : type(tInt), i(i) { }
+        Field(const Activity & act) : type(tInt), i(act.id) { }
+    };
+
+    typedef std::vector<Field> Fields;
+
+    EventType type;
+    Fields fields;
+
+    std::string getS(size_t n) const
+    {
+        assert(n < fields.size());
+        assert(fields[n].type == Field::tString);
+        return fields[n].s;
+    }
+
+    uint64_t getI(size_t n) const
+    {
+        assert(n < fields.size());
+        assert(fields[n].type == Field::tInt);
+        return fields[n].i;
+    }
+};
 
 class Logger
 {
@@ -32,34 +89,16 @@ public:
 
     virtual void warn(const std::string & msg);
 
-    virtual void setExpected(const std::string & label, uint64_t value = 1) { }
-    virtual void setProgress(const std::string & label, uint64_t value = 1) { }
-    virtual void incExpected(const std::string & label, uint64_t value = 1) { }
-    virtual void incProgress(const std::string & label, uint64_t value = 1) { }
-
-private:
-
-    virtual void startActivity(Activity & activity, Verbosity lvl, const FormatOrString & fs) = 0;
-
-    virtual void stopActivity(Activity & activity) = 0;
-
-};
-
-class Activity
-{
-public:
-    Logger & logger;
-
-    Activity(Logger & logger, Verbosity lvl, const FormatOrString & fs)
-        : logger(logger)
+    template<typename... Args>
+    void event(EventType type, const Args & ... args)
     {
-        logger.startActivity(*this, lvl, fs);
+        Event ev;
+        ev.type = type;
+        nop{(ev.fields.emplace_back(Event::Field(args)), 1)...};
+        event(ev);
     }
 
-    ~Activity()
-    {
-        logger.stopActivity(*this);
-    }
+    virtual void event(const Event & ev) = 0;
 };
 
 extern Logger * logger;
diff --git a/src/libutil/util.cc b/src/libutil/util.cc
index 1d1f68fc8..16f4b232e 100644
--- a/src/libutil/util.cc
+++ b/src/libutil/util.cc
@@ -372,7 +372,7 @@ void deletePath(const Path & path)
 
 void deletePath(const Path & path, unsigned long long & bytesFreed)
 {
-    Activity act(*logger, lvlDebug, format("recursively deleting path ‘%1%’") % path);
+    //Activity act(*logger, lvlDebug, format("recursively deleting path ‘%1%’") % path);
     bytesFreed = 0;
     _deletePath(path, bytesFreed);
 }
diff --git a/src/libutil/util.hh b/src/libutil/util.hh
index 5a9c9513f..7ea32e8d9 100644
--- a/src/libutil/util.hh
+++ b/src/libutil/util.hh
@@ -364,6 +364,8 @@ void ignoreException();
 #define ANSI_NORMAL "\e[0m"
 #define ANSI_BOLD "\e[1m"
 #define ANSI_RED "\e[31;1m"
+#define ANSI_GREEN "\e[32;1m"
+#define ANSI_BLUE "\e[34;1m"
 
 
 /* Filter out ANSI escape codes from the given string. If ‘nixOnly’ is
diff --git a/src/nix-channel/nix-channel.cc b/src/nix-channel/nix-channel.cc
index 2aaae2f47..f2742bc3b 100755
--- a/src/nix-channel/nix-channel.cc
+++ b/src/nix-channel/nix-channel.cc
@@ -112,7 +112,6 @@ static void update(const StringSet & channelNames)
             // The URL doesn't unpack directly, so let's try treating it like a full channel folder with files in it
             // Check if the channel advertises a binary cache.
             DownloadRequest request(url + "/binary-cache-url");
-            request.showProgress = DownloadRequest::no;
             try {
                 auto dlRes = dl->download(request);
                 extraAttrs = "binaryCacheURL = \"" + *dlRes.data + "\";";
diff --git a/src/nix-daemon/nix-daemon.cc b/src/nix-daemon/nix-daemon.cc
index d2bb7b8c8..44127635d 100644
--- a/src/nix-daemon/nix-daemon.cc
+++ b/src/nix-daemon/nix-daemon.cc
@@ -82,12 +82,7 @@ class TunnelLogger : public Logger
             defaultLogger->log(lvl, fs);
     }
 
-    void startActivity(Activity & activity, Verbosity lvl, const FormatOrString & fs) override
-    {
-        log(lvl, fs);
-    }
-
-    void stopActivity(Activity & activity) override
+    void event(const Event & ev) override
     {
     }
 };
diff --git a/src/nix-env/nix-env.cc b/src/nix-env/nix-env.cc
index da39bf36a..464bcee4a 100644
--- a/src/nix-env/nix-env.cc
+++ b/src/nix-env/nix-env.cc
@@ -989,7 +989,7 @@ static void opQuery(Globals & globals, Strings opFlags, Strings opArgs)
         try {
             if (i.hasFailed()) continue;
 
-            Activity act(*logger, lvlDebug, format("outputting query result ‘%1%’") % i.attrPath);
+            //Activity act(*logger, lvlDebug, format("outputting query result ‘%1%’") % i.attrPath);
 
             if (globals.prebuiltOnly &&
                 validPaths.find(i.queryOutPath()) == validPaths.end() &&
diff --git a/src/nix-instantiate/nix-instantiate.cc b/src/nix-instantiate/nix-instantiate.cc
index c1b0b0ea0..25f0b1bd6 100644
--- a/src/nix-instantiate/nix-instantiate.cc
+++ b/src/nix-instantiate/nix-instantiate.cc
@@ -19,7 +19,7 @@ using namespace nix;
 
 static Expr * parseStdin(EvalState & state)
 {
-    Activity act(*logger, lvlTalkative, format("parsing standard input"));
+    //Activity act(*logger, lvlTalkative, format("parsing standard input"));
     return state.parseExprFromString(drainFD(0), absPath("."));
 }
 
diff --git a/src/nix/installables.cc b/src/nix/installables.cc
index 4756fc44b..f23308b9b 100644
--- a/src/nix/installables.cc
+++ b/src/nix/installables.cc
@@ -223,9 +223,9 @@ PathSet InstallablesCommand::buildInstallables(ref<Store> store, bool dryRun)
         buildables.insert(b.begin(), b.end());
     }
 
-    printMissing(store, buildables);
-
-    if (!dryRun)
+    if (dryRun)
+        printMissing(store, buildables);
+    else
         store->buildPaths(buildables);
 
     PathSet outPaths;
diff --git a/src/nix/main.cc b/src/nix/main.cc
index 440ced97d..216f0bcce 100644
--- a/src/nix/main.cc
+++ b/src/nix/main.cc
@@ -27,6 +27,7 @@ struct NixArgs : virtual MultiCommand, virtual MixCommonArgs
 
 void mainWrapped(int argc, char * * argv)
 {
+    verbosity = lvlError;
     settings.verboseBuild = false;
 
     initNix();
diff --git a/src/nix/progress-bar.cc b/src/nix/progress-bar.cc
index 69811b282..24e435f81 100644
--- a/src/nix/progress-bar.cc
+++ b/src/nix/progress-bar.cc
@@ -1,8 +1,12 @@
 #include "progress-bar.hh"
 #include "util.hh"
 #include "sync.hh"
+#include "store-api.hh"
 
 #include <map>
+#include <atomic>
+
+#include <sys/ioctl.h>
 
 namespace nix {
 
@@ -12,31 +16,47 @@ private:
 
     struct ActInfo
     {
-        Activity * activity;
-        Verbosity lvl;
-        std::string s;
+        std::string s, s2;
     };
 
-    struct Progress
+    struct DownloadInfo
     {
-        uint64_t expected = 0, progress = 0;
+        std::string uri;
+        uint64_t current = 0;
+        uint64_t expected = 0;
     };
 
     struct State
     {
+        std::map<Activity::t, Path> builds;
+        std::set<Activity::t> runningBuilds;
+        uint64_t succeededBuilds = 0;
+        uint64_t failedBuilds = 0;
+        std::map<Activity::t, Path> substitutions;
+        std::set<Activity::t> runningSubstitutions;
+        uint64_t succeededSubstitutions = 0;
+        uint64_t downloadedBytes = 0; // finished downloads
+        std::map<Activity::t, DownloadInfo> downloads;
         std::list<ActInfo> activities;
-        std::map<Activity *, std::list<ActInfo>::iterator> its;
-        std::map<std::string, Progress> progress;
+        std::map<Activity::t, std::list<ActInfo>::iterator> its;
     };
 
     Sync<State> state_;
 
+    int width = 0;
+
 public:
 
+    ProgressBar()
+    {
+        struct winsize ws;
+        if (ioctl(1, TIOCGWINSZ, &ws) == 0)
+            width = ws.ws_col;
+    }
+
     ~ProgressBar()
     {
         auto state(state_.lock());
-        assert(state->activities.empty());
         writeToStderr("\r\e[K");
     }
 
@@ -52,52 +72,36 @@ public:
         update(state);
     }
 
-    void startActivity(Activity & activity, Verbosity lvl, const FormatOrString & fs) override
-    {
-        if (lvl > verbosity) return;
-        auto state(state_.lock());
-        state->activities.emplace_back(ActInfo{&activity, lvl, fs.s});
-        state->its.emplace(&activity, std::prev(state->activities.end()));
-        update(*state);
-    }
-
-    void stopActivity(Activity & activity) override
-    {
-        auto state(state_.lock());
-        auto i = state->its.find(&activity);
-        if (i == state->its.end()) return;
-        state->activities.erase(i->second);
-        state->its.erase(i);
-        update(*state);
-    }
-
-    void setExpected(const std::string & label, uint64_t value) override
+    void createActivity(State & state, Activity::t activity, const std::string & s)
     {
-        auto state(state_.lock());
-        state->progress[label].expected = value;
-    }
-
-    void setProgress(const std::string & label, uint64_t value) override
-    {
-        auto state(state_.lock());
-        state->progress[label].progress = value;
+        state.activities.emplace_back(ActInfo{s});
+        state.its.emplace(activity, std::prev(state.activities.end()));
     }
 
-    void incExpected(const std::string & label, uint64_t value) override
+    void deleteActivity(State & state, Activity::t activity)
     {
-        auto state(state_.lock());
-        state->progress[label].expected += value;
+        auto i = state.its.find(activity);
+        if (i != state.its.end()) {
+            state.activities.erase(i->second);
+            state.its.erase(i);
+        }
     }
 
-    void incProgress(const std::string & label, uint64_t value) override
+    void updateActivity(State & state, Activity::t activity, const std::string & s2)
     {
-        auto state(state_.lock());
-        state->progress[label].progress += value;
+        auto i = state.its.find(activity);
+        assert(i != state.its.end());
+        ActInfo info = *i->second;
+        state.activities.erase(i->second);
+        info.s2 = s2;
+        state.activities.emplace_back(info);
+        i->second = std::prev(state.activities.end());
     }
 
     void update()
     {
         auto state(state_.lock());
+        update(*state);
     }
 
     void update(State & state)
@@ -113,28 +117,169 @@ public:
 
         if (!state.activities.empty()) {
             if (!status.empty()) line += " ";
-            line += state.activities.rbegin()->s;
+            auto i = state.activities.rbegin();
+            line += i->s;
+            if (!i->s2.empty()) {
+                line += ": ";
+                line += i->s2;
+            }
         }
 
         line += "\e[K";
-        writeToStderr(line);
+        writeToStderr(std::string(line, 0, width - 1));
     }
 
     std::string getStatus(State & state)
     {
         std::string res;
-        for (auto & p : state.progress)
-            if (p.second.expected || p.second.progress) {
-                if (!res.empty()) res += ", ";
-                res += std::to_string(p.second.progress);
-                if (p.second.expected) {
-                    res += "/";
-                    res += std::to_string(p.second.expected);
-                }
-                res += " "; res += p.first;
+
+        if (state.failedBuilds) {
+            if (!res.empty()) res += ", ";
+            res += fmt(ANSI_RED "%d failed" ANSI_NORMAL, state.failedBuilds);
+        }
+
+        if (!state.builds.empty() || state.succeededBuilds)
+        {
+            if (!res.empty()) res += ", ";
+            if (!state.runningBuilds.empty())
+                res += fmt(ANSI_BLUE "%d" "/" ANSI_NORMAL, state.runningBuilds.size());
+            res += fmt(ANSI_GREEN "%d/%d built" ANSI_NORMAL,
+                state.succeededBuilds, state.succeededBuilds + state.builds.size());
+        }
+
+        if (!state.substitutions.empty() || state.succeededSubstitutions) {
+            if (!res.empty()) res += ", ";
+            if (!state.runningSubstitutions.empty())
+                res += fmt(ANSI_BLUE "%d" "/" ANSI_NORMAL, state.runningSubstitutions.size());
+            res += fmt(ANSI_GREEN "%d/%d fetched" ANSI_NORMAL,
+                state.succeededSubstitutions,
+                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);
+        }
+
         return res;
     }
+
+    void event(const Event & ev) override
+    {
+        if (ev.type == evBuildCreated) {
+            auto state(state_.lock());
+            state->builds[ev.getI(0)] = ev.getS(1);
+            update(*state);
+        }
+
+        if (ev.type == evBuildStarted) {
+            auto state(state_.lock());
+            Activity::t act = ev.getI(0);
+            state->runningBuilds.insert(act);
+            auto name = storePathToName(state->builds[act]);
+            if (hasSuffix(name, ".drv"))
+                name.resize(name.size() - 4);
+            createActivity(*state, act, fmt("building " ANSI_BOLD "%s" ANSI_NORMAL, name));
+            update(*state);
+        }
+
+        if (ev.type == evBuildFinished) {
+            auto state(state_.lock());
+            Activity::t act = ev.getI(0);
+            if (ev.getI(1)) {
+                if (state->runningBuilds.count(act))
+                    state->succeededBuilds++;
+            } else
+                state->failedBuilds++;
+            state->runningBuilds.erase(act);
+            state->builds.erase(act);
+            deleteActivity(*state, act);
+            update(*state);
+        }
+
+        if (ev.type == evBuildOutput) {
+            auto state(state_.lock());
+            Activity::t act = ev.getI(0);
+            assert(state->runningBuilds.count(act));
+            updateActivity(*state, act, ev.getS(1));
+            update(*state);
+        }
+
+        if (ev.type == evSubstitutionCreated) {
+            auto state(state_.lock());
+            state->substitutions[ev.getI(0)] = ev.getS(1);
+            update(*state);
+        }
+
+        if (ev.type == evSubstitutionStarted) {
+            auto state(state_.lock());
+            Activity::t act = ev.getI(0);
+            state->runningSubstitutions.insert(act);
+            auto name = storePathToName(state->substitutions[act]);
+            createActivity(*state, act, fmt("fetching " ANSI_BOLD "%s" ANSI_NORMAL, name));
+            update(*state);
+        }
+
+        if (ev.type == evSubstitutionFinished) {
+            auto state(state_.lock());
+            Activity::t act = ev.getI(0);
+            if (ev.getI(1)) {
+                if (state->runningSubstitutions.count(act))
+                    state->succeededSubstitutions++;
+            }
+            state->runningSubstitutions.erase(act);
+            state->substitutions.erase(act);
+            deleteActivity(*state, act);
+            update(*state);
+        }
+
+        if (ev.type == evDownloadCreated) {
+            auto state(state_.lock());
+            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));
+            update(*state);
+        }
+
+        if (ev.type == evDownloadProgress) {
+            auto state(state_.lock());
+            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);
+            update(*state);
+        }
+
+        if (ev.type == evDownloadSucceeded) {
+            auto state(state_.lock());
+            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);
+            update(*state);
+        }
+
+        if (ev.type == evDownloadDestroyed) {
+            auto state(state_.lock());
+            Activity::t act = ev.getI(0);
+            auto i = state->downloads.find(act);
+            if (i != state->downloads.end()) {
+                state->downloads.erase(i);
+                deleteActivity(*state, act);
+                update(*state);
+            }
+        }
+    }
 };
 
 StartProgressBar::StartProgressBar()
diff --git a/src/nix/sigs.cc b/src/nix/sigs.cc
index d8d8c0f53..3dd037716 100644
--- a/src/nix/sigs.cc
+++ b/src/nix/sigs.cc
@@ -42,10 +42,10 @@ struct CmdCopySigs : StorePathsCommand
         std::string doneLabel = "done";
         std::atomic<size_t> added{0};
 
-        logger->setExpected(doneLabel, storePaths.size());
+        //logger->setExpected(doneLabel, storePaths.size());
 
         auto doPath = [&](const Path & storePath) {
-            Activity act(*logger, lvlInfo, format("getting signatures for ‘%s’") % storePath);
+            //Activity act(*logger, lvlInfo, format("getting signatures for ‘%s’") % storePath);
 
             checkInterrupt();
 
@@ -76,7 +76,7 @@ struct CmdCopySigs : StorePathsCommand
                 added += newSigs.size();
             }
 
-            logger->incProgress(doneLabel);
+            //logger->incProgress(doneLabel);
         };
 
         for (auto & storePath : storePaths)
diff --git a/src/nix/verify.cc b/src/nix/verify.cc
index 2f8d02fa0..8facb4bef 100644
--- a/src/nix/verify.cc
+++ b/src/nix/verify.cc
@@ -65,7 +65,7 @@ struct CmdVerify : StorePathsCommand
         std::string untrustedLabel("untrusted");
         std::string corruptedLabel("corrupted");
         std::string failedLabel("failed");
-        logger->setExpected(doneLabel, storePaths.size());
+        //logger->setExpected(doneLabel, storePaths.size());
 
         ThreadPool pool;
 
@@ -73,7 +73,7 @@ struct CmdVerify : StorePathsCommand
             try {
                 checkInterrupt();
 
-                Activity act(*logger, lvlInfo, format("checking ‘%s’") % storePath);
+                //Activity act(*logger, lvlInfo, format("checking ‘%s’") % storePath);
 
                 auto info = store->queryPathInfo(storePath);
 
@@ -85,7 +85,7 @@ struct CmdVerify : StorePathsCommand
                     auto hash = sink.finish();
 
                     if (hash.first != info->narHash) {
-                        logger->incProgress(corruptedLabel);
+                        //logger->incProgress(corruptedLabel);
                         corrupted = 1;
                         printError(
                             format("path ‘%s’ was modified! expected hash ‘%s’, got ‘%s’")
@@ -137,19 +137,19 @@ struct CmdVerify : StorePathsCommand
                     }
 
                     if (!good) {
-                        logger->incProgress(untrustedLabel);
+                        //logger->incProgress(untrustedLabel);
                         untrusted++;
                         printError(format("path ‘%s’ is untrusted") % info->path);
                     }
 
                 }
 
-                logger->incProgress(doneLabel);
+                //logger->incProgress(doneLabel);
                 done++;
 
             } catch (Error & e) {
                 printError(format(ANSI_RED "error:" ANSI_NORMAL " %s") % e.what());
-                logger->incProgress(failedLabel);
+                //logger->incProgress(failedLabel);
                 failed++;
             }
         };