Progress reporting: include origins of running actions

For a user, an important information is to know which actions
are currently running and, more importantly, the target that
caused them. To do so, we need a bit of infrastructure.
- We have to keep track of begin and end of running actions,
  as well as the order in which they were started. That has
  to happen efficiently and in a thread-safe way.
- We have to compute and keep the origin map for actions,
  even if we don't serialize the action graph.

7 files changed, 135 insertions, 30 deletions

diff --git a/src/buildtool/build_engine/target_map/TARGETS b/src/buildtool/build_engine/target_map/TARGETS
index 1426b85f..32dacf40 100644
--- a/src/buildtool/build_engine/target_map/TARGETS
+++ b/src/buildtool/build_engine/target_map/TARGETS
@@ -21,6 +21,7 @@
     , ["src/buildtool/build_engine/expression", "expression"]
     , ["src/buildtool/multithreading", "task"]
     , ["src/buildtool/multithreading", "task_system"]
+    , ["src/buildtool/progress_reporting", "progress"]
     , ["@", "gsl-lite", "", "gsl-lite"]
     ]
   , "stage": ["src", "buildtool", "build_engine", "target_map"]
diff --git a/src/buildtool/build_engine/target_map/result_map.hpp b/src/buildtool/build_engine/target_map/result_map.hpp
index 22c0bd39..61d72bf2 100644
--- a/src/buildtool/build_engine/target_map/result_map.hpp
+++ b/src/buildtool/build_engine/target_map/result_map.hpp
@@ -18,6 +18,7 @@
 #include "src/buildtool/logging/logger.hpp"
 #include "src/buildtool/multithreading/task.hpp"
 #include "src/buildtool/multithreading/task_system.hpp"
+#include "src/buildtool/progress_reporting/progress.hpp"
 #include "src/utils/cpp/hash_combine.hpp"
 
 namespace BuildMaps::Target {
@@ -106,36 +107,30 @@ class ResultTargetMap {
         result.blobs.reserve(nb);
         result.trees.reserve(nt);
 
-        std::unordered_map<
-            std::string,
-            std::vector<std::pair<ConfiguredTarget, std::size_t>>>
-            origin_map;
+        auto& origin_map = Progress::Instance().OriginMap();
+        origin_map.clear();
         origin_map.reserve(na);
-        if constexpr (kIncludeOrigins) {
-            for (const auto& target : targets_) {
+        for (const auto& target : targets_) {
+            std::for_each(target.begin(), target.end(), [&](auto const& el) {
+                auto const& actions = el.second->Actions();
+                std::size_t pos{};
                 std::for_each(
-                    target.begin(), target.end(), [&](auto const& el) {
-                        auto const& actions = el.second->Actions();
-                        std::size_t pos{};
-                        std::for_each(
-                            actions.begin(),
-                            actions.end(),
-                            [&origin_map, &pos, &el](auto const& action) {
-                                std::pair<ConfiguredTarget, std::size_t> origin{
-                                    el.first, pos++};
-                                auto id = action->Id();
-                                if (origin_map.contains(id)) {
-                                    origin_map[id].push_back(origin);
-                                }
-                                else {
-                                    origin_map[id] =
-                                        std::vector<std::pair<ConfiguredTarget,
-                                                              std::size_t>>{
-                                            origin};
-                                }
-                            });
+                    actions.begin(),
+                    actions.end(),
+                    [&origin_map, &pos, &el](auto const& action) {
+                        std::pair<ConfiguredTarget, std::size_t> origin{
+                            el.first, pos++};
+                        auto id = action->Id();
+                        if (origin_map.contains(id)) {
+                            origin_map[id].push_back(origin);
+                        }
+                        else {
+                            origin_map[id] = std::vector<
+                                std::pair<ConfiguredTarget, std::size_t>>{
+                                origin};
+                        }
                     });
-            }
+            });
             // Sort origins to get a reproducible order. We don't expect many
             // origins for a single action, so the cost of comparison is not
             // too important. Moreover, we expect most actions to have a single
diff --git a/src/buildtool/execution_engine/executor/TARGETS b/src/buildtool/execution_engine/executor/TARGETS
index fa1e3e9f..37106368 100644
--- a/src/buildtool/execution_engine/executor/TARGETS
+++ b/src/buildtool/execution_engine/executor/TARGETS
@@ -10,6 +10,7 @@
     , ["src/buildtool/file_system", "file_system_manager"]
     , ["src/buildtool/execution_engine/dag", "dag"]
     , ["src/buildtool/execution_api/common", "common"]
+    , ["src/buildtool/progress_reporting", "progress"]
     , ["@", "gsl-lite", "", "gsl-lite"]
     ]
   , "stage": ["src", "buildtool", "execution_engine", "executor"]
diff --git a/src/buildtool/execution_engine/executor/executor.hpp b/src/buildtool/execution_engine/executor/executor.hpp
index c08a6a2c..9ef38488 100644
--- a/src/buildtool/execution_engine/executor/executor.hpp
+++ b/src/buildtool/execution_engine/executor/executor.hpp
@@ -19,6 +19,7 @@
 #include "src/buildtool/execution_engine/dag/dag.hpp"
 #include "src/buildtool/file_system/file_system_manager.hpp"
 #include "src/buildtool/logging/logger.hpp"
+#include "src/buildtool/progress_reporting/progress.hpp"
 
 /// \brief Implementations for executing actions and uploading artifacts.
 class ExecutorImpl {
@@ -53,6 +54,7 @@ class ExecutorImpl {
             return std::nullopt;
         }
 
+        Progress::Instance().Start(action->Content().Id());
         Statistics::Instance().IncrementActionsQueuedCounter();
 
         logger.Emit(LogLevel::Trace, [&inputs]() {
@@ -290,6 +292,7 @@ class ExecutorImpl {
         else {
             Statistics::Instance().IncrementActionsExecutedCounter();
         }
+        Progress::Instance().Stop(action->Content().Id());
 
         PrintInfo(logger, action->Command(), response);
         bool should_fail_outputs = false;
diff --git a/src/buildtool/progress_reporting/TARGETS b/src/buildtool/progress_reporting/TARGETS
index 99bb1f67..acff7b61 100644
--- a/src/buildtool/progress_reporting/TARGETS
+++ b/src/buildtool/progress_reporting/TARGETS
@@ -1,4 +1,15 @@
-{ "base_progress_reporter":
+{ "progress":
+  { "type": ["@", "rules", "CC", "library"]
+  , "name": ["progress"]
+  , "hdrs": ["progress.hpp"]
+  , "stage": ["src", "buildtool", "progress_reporting"]
+  , "deps":
+    [ ["src/buildtool/build_engine/target_map", "configured_target"]
+    , ["src/buildtool/logging", "logging"]
+    , ["@", "fmt", "", "fmt"]
+    ]
+  }
+, "base_progress_reporter":
   { "type": ["@", "rules", "CC", "library"]
   , "name": ["base_progress_reporter"]
   , "hdrs": ["base_progress_reporter.hpp"]
@@ -7,6 +18,7 @@
   , "deps":
     [ ["src/buildtool/graph_traverser", "graph_traverser"]
     , ["src/buildtool/common", "common"]
+    , "progress"
     ]
   }
 }
diff --git a/src/buildtool/progress_reporting/base_progress_reporter.cpp b/src/buildtool/progress_reporting/base_progress_reporter.cpp
index 531e7804..02a6a162 100644
--- a/src/buildtool/progress_reporting/base_progress_reporter.cpp
+++ b/src/buildtool/progress_reporting/base_progress_reporter.cpp
@@ -4,8 +4,10 @@
 
 #include <mutex>
 
+#include "fmt/core.h"
 #include "src/buildtool/common/statistics.hpp"
 #include "src/buildtool/logging/logger.hpp"
+#include "src/buildtool/progress_reporting/progress.hpp"
 
 auto BaseProgressReporter::Reporter() -> GraphTraverser::progress_reporter_t {
     return [](std::atomic<bool>* done, std::condition_variable* cv) {
@@ -17,14 +19,34 @@ auto BaseProgressReporter::Reporter() -> GraphTraverser::progress_reporter_t {
             cv->wait_for(lock, std::chrono::milliseconds(delay));
             if (not *done) {
                 // Note: order matters; queued has to be queried last
+                std::string sample = Progress::Instance().Sample();
                 int cached = stats.ActionsCachedCounter();
                 int run = stats.ActionsExecutedCounter();
                 int queued = stats.ActionsQueuedCounter();
+                int active = queued - run - cached;
+                std::string now_msg;
+                if (active > 0 and !sample.empty()) {
+                    auto const& origin_map = Progress::Instance().OriginMap();
+                    auto origins = origin_map.find(sample);
+                    if (origins != origin_map.end() and
+                        !origins->second.empty()) {
+                        auto const& origin = origins->second[0];
+                        now_msg = fmt::format(" ({}#{}{})",
+                                              origin.first.target.ToString(),
+                                              origin.second,
+                                              active > 1 ? ", ..." : "");
+                    }
+                    else {
+                        now_msg = fmt::format(
+                            " ({}{})", sample, active > 1 ? ", ..." : "");
+                    }
+                }
                 Logger::Log(LogLevel::Progress,
-                            "{} cached, {} run, {} processing",
+                            "{} cached, {} run, {} processing{}.",
                             cached,
                             run,
-                            queued - run - cached);
+                            active,
+                            now_msg);
             }
             delay = delay * kDelayScalingFactorNumerator /
                     kDelayScalingFactorDenominator;
diff --git a/src/buildtool/progress_reporting/progress.hpp b/src/buildtool/progress_reporting/progress.hpp
new file mode 100644
index 00000000..5940c880
--- /dev/null
+++ b/src/buildtool/progress_reporting/progress.hpp
@@ -0,0 +1,71 @@
+#ifndef INCLUDED_SRC_BUILDTOOL_PROGRESS_REPORTING_PROGRESS_HPP
+#define INCLUDED_SRC_BUILDTOOL_PROGRESS_REPORTING_PROGRESS_HPP
+
+#include <cstdint>
+#include <mutex>
+#include <string>
+#include <unordered_map>
+#include <utility>
+#include <vector>
+
+#include "src/buildtool/build_engine/target_map/configured_target.hpp"
+#include "src/buildtool/logging/logger.hpp"
+
+class Progress {
+  public:
+    [[nodiscard]] static auto Instance() noexcept -> Progress& {
+        static Progress instance{};
+        return instance;
+    }
+
+    void Start(const std::string& id) noexcept {
+        std::unique_lock lock(m_);
+        ++prio_;
+        try {
+            running_.emplace(id, prio_);
+        } catch (...) {
+            Logger::Log(LogLevel::Warning,
+                        "Internal error in progress tracking; progress reports "
+                        "might be incorrect.");
+        }
+    }
+    void Stop(const std::string& id) noexcept {
+        std::unique_lock lock(m_);
+        running_.erase(id);
+    }
+
+    auto Sample() -> std::string {
+        std::unique_lock lock(m_);
+        std::string result;
+        uint64_t started = prio_ + 1;
+        for (auto const& it : running_) {
+            if (it.second < started) {
+                result = it.first;
+                started = it.second;
+            }
+        }
+        return result;
+    }
+
+    // Return a reference to the origin map. It is the responsibility
+    // of the caller to ensure that access happens only happens in a
+    // single-threaded context.
+    auto OriginMap() -> std::unordered_map<
+        std::string,
+        std::vector<
+            std::pair<BuildMaps::Target::ConfiguredTarget, std::size_t>>>& {
+        return origin_map_;
+    }
+
+  private:
+    uint64_t prio_{};
+    std::mutex m_{};
+    std::unordered_map<std::string, uint64_t> running_{};
+    std::unordered_map<
+        std::string,
+        std::vector<
+            std::pair<BuildMaps::Target::ConfiguredTarget, std::size_t>>>
+        origin_map_;
+};
+
+#endif