From 5ed5d7acbd00298df7b4e3a638d731143084da2e Mon Sep 17 00:00:00 2001
From: Eelco Dolstra <edolstra@gmail.com>
Date: Mon, 15 Jun 2020 16:03:29 +0200
Subject: [PATCH] Improve "waiting for locks" messages

These are now shown in the progress bar.

Closes #3577.
---
 src/libmain/progress-bar.cc |  2 +-
 src/libstore/build.cc       | 22 +++++++++++++++++++---
 src/libutil/logging.hh      |  1 +
 3 files changed, 21 insertions(+), 4 deletions(-)

diff --git a/src/libmain/progress-bar.cc b/src/libmain/progress-bar.cc
index 8d0421c2f..6dfc3a4d3 100644
--- a/src/libmain/progress-bar.cc
+++ b/src/libmain/progress-bar.cc
@@ -156,7 +156,7 @@ public:
     {
         auto state(state_.lock());
 
-        if (lvl <= verbosity && !s.empty())
+        if (lvl <= verbosity && !s.empty() && type != actBuildWaiting)
             log(*state, lvl, s + "...");
 
         state->activities.emplace_back(ActInfo());
diff --git a/src/libstore/build.cc b/src/libstore/build.cc
index de393e837..2eb78591b 100644
--- a/src/libstore/build.cc
+++ b/src/libstore/build.cc
@@ -869,6 +869,9 @@ private:
 
     std::unique_ptr<Activity> act;
 
+    /* Activity that denotes waiting for a lock. */
+    std::unique_ptr<Activity> actLock;
+
     std::map<ActivityId, Activity> builderActivities;
 
     /* The remote machine on which we're building. */
@@ -1439,10 +1442,15 @@ void DerivationGoal::tryToBuild()
         lockFiles.insert(worker.store.Store::toRealPath(outPath));
 
     if (!outputLocks.lockPaths(lockFiles, "", false)) {
+        if (!actLock)
+            actLock = std::make_unique<Activity>(*logger, lvlWarn, actBuildWaiting,
+                fmt("waiting for lock on %s", yellowtxt(showPaths(lockFiles))));
         worker.waitForAWhile(shared_from_this());
         return;
     }
 
+    actLock.reset();
+
     /* Now check again whether the outputs are valid.  This is because
        another process may have started building in parallel.  After
        it has finished and released the locks, we can (and should)
@@ -1481,6 +1489,7 @@ void DerivationGoal::tryToBuild()
             case rpAccept:
                 /* Yes, it has started doing so.  Wait until we get
                    EOF from the hook. */
+                actLock.reset();
                 result.startTime = time(0); // inexact
                 state = &DerivationGoal::buildDone;
                 started();
@@ -1488,6 +1497,9 @@ void DerivationGoal::tryToBuild()
             case rpPostpone:
                 /* Not now; wait until at least one child finishes or
                    the wake-up timeout expires. */
+                if (!actLock)
+                    actLock = std::make_unique<Activity>(*logger, lvlWarn, actBuildWaiting,
+                        fmt("waiting for a machine to build '%s'", yellowtxt(worker.store.printStorePath(drvPath))));
                 worker.waitForAWhile(shared_from_this());
                 outputLocks.unlock();
                 return;
@@ -1497,6 +1509,8 @@ void DerivationGoal::tryToBuild()
         }
     }
 
+    actLock.reset();
+
     /* Make sure that we are allowed to start a build.  If this
        derivation prefers to be done locally, do it even if
        maxBuildJobs is 0. */
@@ -1524,7 +1538,9 @@ void DerivationGoal::tryLocalBuild() {
                uid. */
             buildUser->kill();
         } else {
-            debug("waiting for build users");
+            if (!actLock)
+                actLock = std::make_unique<Activity>(*logger, lvlWarn, actBuildWaiting,
+                    fmt("waiting for UID to build '%s'", yellowtxt(worker.store.printStorePath(drvPath))));
             worker.waitForAWhile(shared_from_this());
             return;
         }
@@ -1535,6 +1551,8 @@ void DerivationGoal::tryLocalBuild() {
 #endif
     }
 
+    actLock.reset();
+
     try {
 
         /* Okay, we have to build. */
@@ -4863,8 +4881,6 @@ void Worker::waitForInput()
        up after a few seconds at most. */
     if (!waitingForAWhile.empty()) {
         useTimeout = true;
-        if (lastWokenUp == steady_time_point::min())
-            printInfo("waiting for locks, build slots or build users...");
         if (lastWokenUp == steady_time_point::min() || lastWokenUp > before) lastWokenUp = before;
         timeout = std::max(1L,
             (long) std::chrono::duration_cast<std::chrono::seconds>(
diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh
index b99b246c3..b1583eced 100644
--- a/src/libutil/logging.hh
+++ b/src/libutil/logging.hh
@@ -18,6 +18,7 @@ typedef enum {
     actSubstitute = 108,
     actQueryPathInfo = 109,
     actPostBuildHook = 110,
+    actBuildWaiting = 111,
 } ActivityType;
 
 typedef enum {