Keep track of time required to load builds

src/hydra-queue-runner/hydra-queue-runner.cc

@@ -548,6 +548,8 @@ void State::dumpStatus(Connection & conn, bool log)
         root.attr("bytesSent", bytesSent);
         root.attr("bytesReceived", bytesReceived);
         root.attr("nrBuildsRead", nrBuildsRead);
+        root.attr("buildReadTimeMs", buildReadTimeMs);
+        root.attr("buildReadTimeAvgMs", nrBuildsRead == 0 ? 0.0 :  (float) buildReadTimeMs / nrBuildsRead);
         root.attr("nrBuildsDone", nrBuildsDone);
         root.attr("nrStepsStarted", nrStepsStarted);
         root.attr("nrStepsDone", nrStepsDone);

src/hydra-queue-runner/queue-monitor.cc

@@ -247,6 +247,8 @@ bool State::getQueuedBuilds(Connection & conn, ref<Store> localStore,
         if (i == newBuildsByID.end()) continue;
         auto build = i->second;
 
+        auto now1 = std::chrono::steady_clock::now();
+
         newRunnable.clear();
         nrAdded = 0;
         try {
@@ -256,6 +258,10 @@ bool State::getQueuedBuilds(Connection & conn, ref<Store> localStore,
             throw;
         }
 
+        auto now2 = std::chrono::steady_clock::now();
+
+        buildReadTimeMs += std::chrono::duration_cast<std::chrono::milliseconds>(now2 - now1).count();
+
         /* Add the new runnable build steps to ‘runnable’ and wake up
            the builder threads. */
         printMsg(lvlChatty, format("got %1% new runnable steps from %2% new builds") % newRunnable.size() % nrAdded);

src/hydra-queue-runner/state.hh

@@ -294,6 +294,7 @@ private:
     /* Various stats. */
     time_t startedAt;
     counter nrBuildsRead{0};
+    counter buildReadTimeMs{0};
     counter nrBuildsDone{0};
     counter nrStepsStarted{0};
     counter nrStepsDone{0};