From 092d60735b1cf21943af40a96070d856421121f4 Mon Sep 17 00:00:00 2001
From: Eelco Dolstra <eelco.dolstra@logicblox.com>
Date: Mon, 17 Aug 2015 15:45:44 +0200
Subject: [PATCH] Keep track of wait time per system type

I.e., how much time the currently runnable steps per system type have
been waiting. This is useful for deciding whether to provision more
machines.
---
 src/hydra-queue-runner/dispatcher.cc         | 28 +++++++++++++++-----
 src/hydra-queue-runner/hydra-queue-runner.cc |  5 +++-
 src/hydra-queue-runner/state.hh              |  8 +++++-
 3 files changed, 32 insertions(+), 9 deletions(-)

diff --git a/src/hydra-queue-runner/dispatcher.cc b/src/hydra-queue-runner/dispatcher.cc
index d6a02d4a..b5f65a78 100644
--- a/src/hydra-queue-runner/dispatcher.cc
+++ b/src/hydra-queue-runner/dispatcher.cc
@@ -16,6 +16,7 @@ void State::makeRunnable(Step::ptr step)
         assert(step_->created);
         assert(!step->finished);
         assert(step_->deps.empty());
+        step_->runnableSince = std::chrono::system_clock::now();
     }
 
     {
@@ -143,7 +144,12 @@ system_time State::doDispatch()
            FIXME: O(n lg n); obviously, it would be better to keep a
            runnable queue sorted by priority. */
         std::vector<Step::ptr> runnableSorted;
-        std::unordered_map<std::string, unsigned int> runnablePerType;
+        struct RunnablePerType
+        {
+            unsigned int count{0};
+            std::chrono::seconds waitTime{0};
+        };
+        std::unordered_map<std::string, RunnablePerType> runnablePerType;
         {
             auto runnable_(runnable.lock());
             runnableSorted.reserve(runnable_->size());
@@ -158,12 +164,14 @@ system_time State::doDispatch()
 
                 ++i;
 
-                runnablePerType[step->systemType]++;
+                auto & r = runnablePerType[step->systemType];
+                r.count++;
 
                 /* Skip previously failed steps that aren't ready
                    to be retried. */
                 {
                     auto step_(step->state.lock());
+                    r.waitTime += std::chrono::duration_cast<std::chrono::seconds>(now - step_->runnableSince);
                     if (step_->tries > 0 && step_->after > now) {
                         if (step_->after < sleepUntil)
                             sleepUntil = step_->after;
@@ -219,8 +227,9 @@ system_time State::doDispatch()
                             break;
                         } else ++i;
                     assert(removed);
-                    assert(runnablePerType[step->systemType]);
-                    runnablePerType[step->systemType]--;
+                    auto & r = runnablePerType[step->systemType];
+                    assert(r.count);
+                    r.count--;
                 }
 
                 /* Make a slot reservation and start a thread to
@@ -243,10 +252,15 @@ system_time State::doDispatch()
             for (auto & i : *machineTypes_)
                 i.second.runnable = 0;
 
-            for (auto & i : runnablePerType)
-                (*machineTypes_)[i.first].runnable = i.second;
+            for (auto & i : runnablePerType) {
+                auto & j = (*machineTypes_)[i.first];
+                j.runnable = i.second.count;
+                j.waitTime = i.second.waitTime;
+            }
         }
 
+        lastDispatcherCheck = std::chrono::system_clock::to_time_t(now);
+
     } while (keepGoing);
 
     return sleepUntil;
@@ -309,6 +323,6 @@ State::MachineReservation::~MachineReservation()
         assert(machineType.running);
         machineType.running--;
         if (machineType.running == 0)
-            machineType.lastActive = time(0);
+            machineType.lastActive = std::chrono::system_clock::now();
     }
 }
diff --git a/src/hydra-queue-runner/hydra-queue-runner.cc b/src/hydra-queue-runner/hydra-queue-runner.cc
index 61508ae6..43c865e2 100644
--- a/src/hydra-queue-runner/hydra-queue-runner.cc
+++ b/src/hydra-queue-runner/hydra-queue-runner.cc
@@ -484,8 +484,11 @@ void State::dumpStatus(Connection & conn, bool log)
                 JSONObject nested2(out);
                 nested2.attr("runnable", i.second.runnable);
                 nested2.attr("running", i.second.running);
+                if (i.second.runnable > 0)
+                    nested2.attr("waitTime", i.second.waitTime.count() +
+                        i.second.runnable * (time(0) - lastDispatcherCheck));
                 if (i.second.running == 0)
-                    nested2.attr("lastActive", i.second.lastActive);
+                    nested2.attr("lastActive", std::chrono::system_clock::to_time_t(i.second.lastActive));
             }
         }
     }
diff --git a/src/hydra-queue-runner/state.hh b/src/hydra-queue-runner/state.hh
index 7d376b70..2a11f6a4 100644
--- a/src/hydra-queue-runner/state.hh
+++ b/src/hydra-queue-runner/state.hh
@@ -175,6 +175,9 @@ struct Step
 
         /* The lowest ID of any build depending on this step. */
         BuildID lowestBuildID{std::numeric_limits<BuildID>::max()};
+
+        /* The time at which this step became runnable. */
+        system_time runnableSince;
     };
 
     std::atomic_bool finished{false}; // debugging
@@ -324,7 +327,8 @@ private:
     struct MachineType
     {
         unsigned int runnable{0}, running{0};
-        time_t lastActive{0};
+        system_time lastActive;
+        std::chrono::seconds waitTime; // time runnable steps have been waiting
     };
 
     Sync<std::map<std::string, MachineType>> machineTypes;
@@ -339,6 +343,8 @@ private:
         ~MachineReservation();
     };
 
+    std::atomic<time_t> lastDispatcherCheck{0};
+
 public:
     State();