More progress indicator improvements

Fixes #1599.

src/build-remote/build-remote.cc

@@ -201,25 +201,29 @@ connected:
         auto inputs = readStrings<PathSet>(source);
         auto outputs = readStrings<PathSet>(source);
 
+        AutoCloseFD uploadLock = openLockFile(currentLoad + "/" + escapeUri(storeUri) + ".upload-lock", true);
+
         {
             Activity act(*logger, lvlTalkative, actUnknown, fmt("waiting for the upload lock to '%s'", storeUri));
 
-            AutoCloseFD uploadLock = openLockFile(currentLoad + "/" + escapeUri(storeUri) + ".upload-lock", true);
-
             auto old = signal(SIGALRM, handleAlarm);
             alarm(15 * 60);
             if (!lockFile(uploadLock.get(), ltWrite, true))
                 printError("somebody is hogging the upload lock for '%s', continuing...");
             alarm(0);
             signal(SIGALRM, old);
-            copyPaths(store, ref<Store>(sshStore), inputs, NoRepair, NoCheckSigs);
-            uploadLock = -1;
         }
 
+        {
+            Activity act(*logger, lvlTalkative, actUnknown, fmt("copying dependencies to '%s'", storeUri));
+            copyPaths(store, ref<Store>(sshStore), inputs, NoRepair, NoCheckSigs);
+        }
+
+        uploadLock = -1;
+
         BasicDerivation drv(readDerivation(store->realStoreDir + "/" + baseNameOf(drvPath)));
         drv.inputSrcs = inputs;
 
-        printInfo("building '%s' on '%s'", drvPath, storeUri);
         auto result = sshStore->buildDerivation(drvPath, drv);
 
         if (!result.success())
@@ -230,6 +234,7 @@ connected:
             if (!store->isValidPath(path)) missing.insert(path);
 
         if (!missing.empty()) {
+            Activity act(*logger, lvlTalkative, actUnknown, fmt("copying outputs from '%s'", storeUri));
             setenv("NIX_HELD_LOCKS", concatStringsSep(" ", missing).c_str(), 1); /* FIXME: ugly */
             copyPaths(ref<Store>(sshStore), store, missing, NoRepair, NoCheckSigs);
         }

src/libstore/build.cc

@@ -1403,7 +1403,7 @@ void DerivationGoal::tryToBuild()
 
     auto started = [&]() {
         act = std::make_unique<Activity>(*logger, lvlInfo, actBuild,
-            fmt("building '%s'", drvPath),
+            hook ? fmt("building '%s' on '%s'", drvPath, machineName) : fmt("building '%s'", drvPath),
             Logger::Fields{drvPath, hook ? machineName : ""});
         mcRunningBuilds = std::make_unique<MaintainCount<uint64_t>>(worker.runningBuilds);
         worker.updateProgress();
@@ -1659,7 +1659,7 @@ HookReply DerivationGoal::tryBuildHook()
         string reply;
         while (true) {
             string s = readLine(worker.hook->fromHook.readSide.get());
-            if (handleJSONLogMessage(s, worker.act, worker.hook->activities))
+            if (handleJSONLogMessage(s, worker.act, worker.hook->activities, true))
                 ;
             else if (string(s, 0, 2) == "# ") {
                 reply = string(s, 2);
@@ -3270,7 +3270,7 @@ void DerivationGoal::handleChildOutput(int fd, const string & data)
     if (hook && fd == hook->fromHook.readSide.get()) {
         for (auto c : data)
             if (c == '\n') {
-                handleJSONLogMessage(currentHookLine, worker.act, hook->activities);
+                handleJSONLogMessage(currentHookLine, worker.act, hook->activities, true);
                 currentHookLine.clear();
             } else
                 currentHookLine += c;
@@ -3287,7 +3287,7 @@ void DerivationGoal::handleEOF(int fd)
 
 void DerivationGoal::flushLine()
 {
-    if (handleJSONLogMessage(currentLogLine, *act, builderActivities))
+    if (handleJSONLogMessage(currentLogLine, *act, builderActivities, false))
         ;
 
     else {

src/libstore/store-api.cc

@@ -565,8 +565,16 @@ void Store::buildPaths(const PathSet & paths, BuildMode buildMode)
 void copyStorePath(ref<Store> srcStore, ref<Store> dstStore,
     const Path & storePath, RepairFlag repair, CheckSigsFlag checkSigs)
 {
-    Activity act(*logger, lvlInfo, actCopyPath, fmt("copying path '%s'", storePath),
+    auto srcUri = srcStore->getUri();
-        {storePath, srcStore->getUri(), dstStore->getUri()});
+    auto dstUri = dstStore->getUri();
+
+    Activity act(*logger, lvlInfo, actCopyPath,
+        srcUri == "local"
+          ? fmt("copying path '%s' to '%s'", storePath, dstUri)
+          : dstUri == "local"
+            ? fmt("copying path '%s' from '%s'", storePath, srcUri)
+            : fmt("copying path '%s' from '%s' to '%s'", storePath, srcUri, dstUri),
+        {storePath, srcUri, dstUri});
     PushActivity pact(act.id);
 
     auto info = srcStore->queryPathInfo(storePath);

src/libutil/logging.cc

@@ -176,7 +176,7 @@ static Logger::Fields getFields(nlohmann::json & json)
 }
 
 bool handleJSONLogMessage(const std::string & msg,
-    const Activity & act, std::map<ActivityId, Activity> & activities)
+    const Activity & act, std::map<ActivityId, Activity> & activities, bool trusted)
 {
     if (!hasPrefix(msg, "@nix ")) return false;
 
@@ -187,7 +187,7 @@ bool handleJSONLogMessage(const std::string & msg,
 
         if (action == "start") {
             auto type = (ActivityType) json["type"];
-            if (type == actDownload || type == actUnknown)
+            if (trusted || type == actDownload)
                 activities.emplace(std::piecewise_construct,
                     std::forward_as_tuple(json["id"]),
                     std::forward_as_tuple(*logger, (Verbosity) json["level"], type,

src/libutil/logging.hh

@@ -133,7 +133,8 @@ Logger * makeDefaultLogger();
 Logger * makeJSONLogger(Logger & prevLogger);
 
 bool handleJSONLogMessage(const std::string & msg,
-    const Activity & act, std::map<ActivityId, Activity> & activities);
+    const Activity & act, std::map<ActivityId, Activity> & activities,
+    bool trusted);
 
 extern Verbosity verbosity; /* suppress msgs > this */