Use a steady clock for timeouts

Fixes #1146.
This commit is contained in:
Eelco Dolstra 2016-12-06 21:58:04 +01:00
parent 7a3e7d0e61
commit ceeedb58d2
No known key found for this signature in database
GPG key ID: 8170B4726D7198DE
2 changed files with 29 additions and 22 deletions

View file

@ -17,9 +17,9 @@
#include <sstream> #include <sstream>
#include <thread> #include <thread>
#include <future> #include <future>
#include <chrono>
#include <limits.h> #include <limits.h>
#include <time.h>
#include <sys/time.h> #include <sys/time.h>
#include <sys/wait.h> #include <sys/wait.h>
#include <sys/types.h> #include <sys/types.h>
@ -187,6 +187,9 @@ bool CompareGoalPtrs::operator() (const GoalPtr & a, const GoalPtr & b) {
} }
typedef std::chrono::time_point<std::chrono::steady_clock> steady_time_point;
/* A mapping used to remember for each child process to what goal it /* A mapping used to remember for each child process to what goal it
belongs, and file descriptors for receiving log data and output belongs, and file descriptors for receiving log data and output
path creation commands. */ path creation commands. */
@ -197,8 +200,8 @@ struct Child
set<int> fds; set<int> fds;
bool respectTimeouts; bool respectTimeouts;
bool inBuildSlot; bool inBuildSlot;
time_t lastOutput; /* time we last got output on stdout/stderr */ steady_time_point lastOutput; /* time we last got output on stdout/stderr */
time_t timeStarted; steady_time_point timeStarted;
}; };
@ -238,7 +241,7 @@ private:
WeakGoals waitingForAWhile; WeakGoals waitingForAWhile;
/* Last time the goals in `waitingForAWhile' where woken up. */ /* Last time the goals in `waitingForAWhile' where woken up. */
time_t lastWokenUp; steady_time_point lastWokenUp;
/* Cache for pathContentsGood(). */ /* Cache for pathContentsGood(). */
std::map<Path, bool> pathContentsGoodCache; std::map<Path, bool> pathContentsGoodCache;
@ -3390,7 +3393,7 @@ Worker::Worker(LocalStore & store)
if (working) abort(); if (working) abort();
working = true; working = true;
nrLocalBuilds = 0; nrLocalBuilds = 0;
lastWokenUp = 0; lastWokenUp = steady_time_point::min();
permanentFailure = false; permanentFailure = false;
timedOut = false; timedOut = false;
} }
@ -3499,7 +3502,7 @@ void Worker::childStarted(GoalPtr goal, const set<int> & fds,
child.goal = goal; child.goal = goal;
child.goal2 = goal.get(); child.goal2 = goal.get();
child.fds = fds; child.fds = fds;
child.timeStarted = child.lastOutput = time(0); child.timeStarted = child.lastOutput = steady_time_point::clock::now();
child.inBuildSlot = inBuildSlot; child.inBuildSlot = inBuildSlot;
child.respectTimeouts = respectTimeouts; child.respectTimeouts = respectTimeouts;
children.emplace_back(child); children.emplace_back(child);
@ -3618,35 +3621,38 @@ void Worker::waitForInput()
bool useTimeout = false; bool useTimeout = false;
struct timeval timeout; struct timeval timeout;
timeout.tv_usec = 0; timeout.tv_usec = 0;
time_t before = time(0); auto before = steady_time_point::clock::now();
/* If we're monitoring for silence on stdout/stderr, or if there /* If we're monitoring for silence on stdout/stderr, or if there
is a build timeout, then wait for input until the first is a build timeout, then wait for input until the first
deadline for any child. */ deadline for any child. */
assert(sizeof(time_t) >= sizeof(long)); auto nearest = steady_time_point::max(); // nearest deadline
time_t nearest = LONG_MAX; // nearest deadline
for (auto & i : children) { for (auto & i : children) {
if (!i.respectTimeouts) continue; if (!i.respectTimeouts) continue;
if (settings.maxSilentTime != 0) if (settings.maxSilentTime != 0)
nearest = std::min(nearest, i.lastOutput + settings.maxSilentTime); nearest = std::min(nearest, i.lastOutput + std::chrono::seconds(settings.maxSilentTime));
if (settings.buildTimeout != 0) if (settings.buildTimeout != 0)
nearest = std::min(nearest, i.timeStarted + settings.buildTimeout); nearest = std::min(nearest, i.timeStarted + std::chrono::seconds(settings.buildTimeout));
} }
if (nearest != LONG_MAX) { if (nearest != steady_time_point::max()) {
timeout.tv_sec = std::max((time_t) 1, nearest - before); timeout.tv_sec = std::max(1L, std::chrono::duration_cast<std::chrono::seconds>(nearest - before).count());
useTimeout = true; useTimeout = true;
printMsg(lvlVomit, format("sleeping %1% seconds") % timeout.tv_sec);
} }
/* If we are polling goals that are waiting for a lock, then wake /* If we are polling goals that are waiting for a lock, then wake
up after a few seconds at most. */ up after a few seconds at most. */
if (!waitingForAWhile.empty()) { if (!waitingForAWhile.empty()) {
useTimeout = true; useTimeout = true;
if (lastWokenUp == 0) if (lastWokenUp == steady_time_point::min())
printError("waiting for locks or build slots..."); printError("waiting for locks or build slots...");
if (lastWokenUp == 0 || lastWokenUp > before) lastWokenUp = before; if (lastWokenUp == steady_time_point::min() || lastWokenUp > before) lastWokenUp = before;
timeout.tv_sec = std::max((time_t) 1, (time_t) (lastWokenUp + settings.pollInterval - before)); timeout.tv_sec = std::max(1L,
} else lastWokenUp = 0; std::chrono::duration_cast<std::chrono::seconds>(
lastWokenUp + std::chrono::seconds(settings.pollInterval) - before).count());
} else lastWokenUp = steady_time_point::min();
if (useTimeout)
vomit("sleeping %d seconds", timeout.tv_sec);
/* Use select() to wait for the input side of any logger pipe to /* Use select() to wait for the input side of any logger pipe to
become `available'. Note that `available' (i.e., non-blocking) become `available'. Note that `available' (i.e., non-blocking)
@ -3666,7 +3672,7 @@ void Worker::waitForInput()
throw SysError("waiting for input"); throw SysError("waiting for input");
} }
time_t after = time(0); auto after = steady_time_point::clock::now();
/* Process all available file descriptors. */ /* Process all available file descriptors. */
decltype(children)::iterator i; decltype(children)::iterator i;
@ -3704,7 +3710,7 @@ void Worker::waitForInput()
if (goal->getExitCode() == Goal::ecBusy && if (goal->getExitCode() == Goal::ecBusy &&
settings.maxSilentTime != 0 && settings.maxSilentTime != 0 &&
j->respectTimeouts && j->respectTimeouts &&
after - j->lastOutput >= (time_t) settings.maxSilentTime) after - j->lastOutput >= std::chrono::seconds(settings.maxSilentTime))
{ {
printError( printError(
format("%1% timed out after %2% seconds of silence") format("%1% timed out after %2% seconds of silence")
@ -3715,7 +3721,7 @@ void Worker::waitForInput()
else if (goal->getExitCode() == Goal::ecBusy && else if (goal->getExitCode() == Goal::ecBusy &&
settings.buildTimeout != 0 && settings.buildTimeout != 0 &&
j->respectTimeouts && j->respectTimeouts &&
after - j->timeStarted >= (time_t) settings.buildTimeout) after - j->timeStarted >= std::chrono::seconds(settings.buildTimeout))
{ {
printError( printError(
format("%1% timed out after %2% seconds") format("%1% timed out after %2% seconds")
@ -3724,7 +3730,7 @@ void Worker::waitForInput()
} }
} }
if (!waitingForAWhile.empty() && lastWokenUp + (time_t) settings.pollInterval <= after) { if (!waitingForAWhile.empty() && lastWokenUp + std::chrono::seconds(settings.pollInterval) <= after) {
lastWokenUp = after; lastWokenUp = after;
for (auto & i : waitingForAWhile) { for (auto & i : waitingForAWhile) {
GoalPtr goal = i.lock(); GoalPtr goal = i.lock();

View file

@ -79,6 +79,7 @@ extern Verbosity verbosity; /* suppress msgs > this */
#define printError(args...) printMsg(lvlError, args) #define printError(args...) printMsg(lvlError, args)
#define printInfo(args...) printMsg(lvlInfo, args) #define printInfo(args...) printMsg(lvlInfo, args)
#define debug(args...) printMsg(lvlDebug, args) #define debug(args...) printMsg(lvlDebug, args)
#define vomit(args...) printMsg(lvlVomit, args)
void warnOnce(bool & haveWarned, const FormatOrString & fs); void warnOnce(bool & haveWarned, const FormatOrString & fs);