Commit 3396d608 authored by Adam Simpkins's avatar Adam Simpkins Committed by Facebook Github Bot

additional minor cleanup to the TimeUtil code

Summary:
- Fix TimePoint to use steady_clock rather than system_clock
- Use nanoseconds instead of milliseconds in most locations

This code should probably also be moved into a folly::testing namespace or
something.  This class is pretty specific to unit tests, and `folly::TimePoint`
seems like too generic of a name for it.  However, just to keep things simple
I'm not doing that as part of this diff yet.

Reviewed By: yfeldblum

Differential Revision: D5175630

fbshipit-source-id: 26490fc7ff1b25fb86f09309e81108828cd0f091
parent c2bd7be5
...@@ -151,19 +151,19 @@ static int64_t determineSchedstatUnits() { ...@@ -151,19 +151,19 @@ static int64_t determineSchedstatUnits() {
* Determine how long this process has spent waiting to get scheduled on the * Determine how long this process has spent waiting to get scheduled on the
* CPU. * CPU.
* *
* Returns the number of milliseconds spent waiting, or -1 if the amount of * Returns the number of nanoseconds spent waiting, or -1 if the amount of
* time cannot be determined. * time cannot be determined.
*/ */
static milliseconds getTimeWaitingMS(pid_t tid) { static nanoseconds getSchedTimeWaiting(pid_t tid) {
#ifndef __linux__ #ifndef __linux__
(void)tid; (void)tid;
return milliseconds(0); return nanoseconds(0);
#else #else
static int64_t timeUnits = determineSchedstatUnits(); static int64_t timeUnits = determineSchedstatUnits();
if (timeUnits < 0) { if (timeUnits < 0) {
// We couldn't figure out how many jiffies there are in a second. // We couldn't figure out how many jiffies there are in a second.
// Don't bother reading the schedstat info if we can't interpret it. // Don't bother reading the schedstat info if we can't interpret it.
return milliseconds(0); return nanoseconds(0);
} }
int fd = -1; int fd = -1;
...@@ -201,28 +201,28 @@ static milliseconds getTimeWaitingMS(pid_t tid) { ...@@ -201,28 +201,28 @@ static milliseconds getTimeWaitingMS(pid_t tid) {
} }
close(fd); close(fd);
return duration_cast<milliseconds>(nanoseconds(waitingJiffies * timeUnits)); return nanoseconds(waitingJiffies * timeUnits);
} catch (const std::runtime_error& e) { } catch (const std::runtime_error& e) {
if (fd >= 0) { if (fd >= 0) {
close(fd); close(fd);
} }
LOG(ERROR) << "error determining process wait time: %s" << e.what(); LOG(ERROR) << "error determining process wait time: %s" << e.what();
return milliseconds(0); return nanoseconds(0);
} }
#endif #endif
} }
void TimePoint::reset() { void TimePoint::reset() {
// Remember the current time // Remember the current time
timeStart_ = system_clock::now(); timeStart_ = steady_clock::now();
// Remember how long this process has spent waiting to be scheduled // Remember how long this process has spent waiting to be scheduled
tid_ = getOSThreadID(); tid_ = getOSThreadID();
timeWaiting_ = getTimeWaitingMS(tid_); timeWaiting_ = getSchedTimeWaiting(tid_);
// In case it took a while to read the schedstat info, // In case it took a while to read the schedstat info,
// also record the time after the schedstat check // also record the time after the schedstat check
timeEnd_ = system_clock::now(); timeEnd_ = steady_clock::now();
} }
std::ostream& operator<<(std::ostream& os, const TimePoint& timePoint) { std::ostream& operator<<(std::ostream& os, const TimePoint& timePoint) {
...@@ -232,16 +232,18 @@ std::ostream& operator<<(std::ostream& os, const TimePoint& timePoint) { ...@@ -232,16 +232,18 @@ std::ostream& operator<<(std::ostream& os, const TimePoint& timePoint) {
return os; return os;
} }
bool bool checkTimeout(
checkTimeout(const TimePoint& start, const TimePoint& end, const TimePoint& start,
milliseconds expectedMS, bool allowSmaller, const TimePoint& end,
milliseconds tolerance) { nanoseconds expected,
bool allowSmaller,
nanoseconds tolerance) {
auto elapsedTime = end.getTimeStart() - start.getTimeEnd(); auto elapsedTime = end.getTimeStart() - start.getTimeEnd();
if (!allowSmaller) { if (!allowSmaller) {
// Timeouts should never fire before the time was up. // Timeouts should never fire before the time was up.
// Allow 1ms of wiggle room for rounding errors. // Allow 1ms of wiggle room for rounding errors.
if (elapsedTime < (expectedMS - milliseconds(1))) { if (elapsedTime < (expected - milliseconds(1))) {
return false; return false;
} }
} }
...@@ -251,26 +253,26 @@ checkTimeout(const TimePoint& start, const TimePoint& end, ...@@ -251,26 +253,26 @@ checkTimeout(const TimePoint& start, const TimePoint& end,
// If the system is under heavy load, our process may have had to wait for a // If the system is under heavy load, our process may have had to wait for a
// while to be run. The time spent waiting for the processor shouldn't // while to be run. The time spent waiting for the processor shouldn't
// count against us, so exclude this time from the check. // count against us, so exclude this time from the check.
milliseconds excludedMS; nanoseconds timeExcluded;
if (end.getTid() != start.getTid()) { if (end.getTid() != start.getTid()) {
// We can only correctly compute the amount of time waiting to be scheduled // We can only correctly compute the amount of time waiting to be scheduled
// if both TimePoints were set in the same thread. // if both TimePoints were set in the same thread.
excludedMS = milliseconds(0); timeExcluded = nanoseconds(0);
} else { } else {
excludedMS = end.getTimeWaiting() - start.getTimeWaiting(); timeExcluded = end.getTimeWaiting() - start.getTimeWaiting();
assert(end.getTimeWaiting() >= start.getTimeWaiting()); assert(end.getTimeWaiting() >= start.getTimeWaiting());
// Add a tolerance here due to precision issues on linux, see below note. // Add a tolerance here due to precision issues on linux, see below note.
assert((elapsedTime + tolerance) >= excludedMS); assert((elapsedTime + tolerance) >= timeExcluded);
} }
milliseconds effectiveElapsedMS = milliseconds(0); nanoseconds effectiveElapsedTime(0);
if (elapsedTime > excludedMS) { if (elapsedTime > timeExcluded) {
effectiveElapsedMS = duration_cast<milliseconds>(elapsedTime) - excludedMS; effectiveElapsedTime = elapsedTime - timeExcluded;
} }
// On x86 Linux, sleep calls generally have precision only to the nearest // On x86 Linux, sleep calls generally have precision only to the nearest
// millisecond. The tolerance parameter lets users allow a few ms of slop. // millisecond. The tolerance parameter lets users allow a few ms of slop.
milliseconds overrun = effectiveElapsedMS - expectedMS; auto overrun = effectiveElapsedTime - expected;
if (overrun > tolerance) { if (overrun > tolerance) {
return false; return false;
} }
......
...@@ -22,6 +22,15 @@ ...@@ -22,6 +22,15 @@
namespace folly { namespace folly {
/**
* A class for tracking time durations in test code.
*
* This is primarily useful for testing timeout functionality. When comparing
* the differences between two TimePoints, it can exclude time spent waiting on
* the OS scheduler. This helps avoid spurious test failures when timeouts are
* exceeded by longer than expected simply because the underlying system was
* busy and could not schedule this thread in time.
*/
class TimePoint { class TimePoint {
public: public:
explicit TimePoint(bool set = true) explicit TimePoint(bool set = true)
...@@ -39,19 +48,19 @@ class TimePoint { ...@@ -39,19 +48,19 @@ class TimePoint {
timeWaiting_.count() == 0); timeWaiting_.count() == 0);
} }
std::chrono::system_clock::time_point getTime() const { std::chrono::steady_clock::time_point getTime() const {
return timeStart_; return timeStart_;
} }
std::chrono::system_clock::time_point getTimeStart() const { std::chrono::steady_clock::time_point getTimeStart() const {
return timeStart_; return timeStart_;
} }
std::chrono::system_clock::time_point getTimeEnd() const { std::chrono::steady_clock::time_point getTimeEnd() const {
return timeStart_; return timeStart_;
} }
std::chrono::milliseconds getTimeWaiting() const { std::chrono::nanoseconds getTimeWaiting() const {
return timeWaiting_; return timeWaiting_;
} }
...@@ -60,19 +69,18 @@ class TimePoint { ...@@ -60,19 +69,18 @@ class TimePoint {
} }
private: private:
std::chrono::system_clock::time_point timeStart_; std::chrono::steady_clock::time_point timeStart_;
std::chrono::system_clock::time_point timeEnd_; std::chrono::steady_clock::time_point timeEnd_;
std::chrono::milliseconds timeWaiting_{0}; std::chrono::nanoseconds timeWaiting_{0};
pid_t tid_; pid_t tid_;
}; };
std::ostream& operator<<(std::ostream& os, const TimePoint& timePoint); std::ostream& operator<<(std::ostream& os, const TimePoint& timePoint);
bool checkTimeout(const TimePoint& start, bool checkTimeout(
const TimePoint& end, const TimePoint& start,
std::chrono::milliseconds expectedMS, const TimePoint& end,
bool allowSmaller, std::chrono::nanoseconds expected,
std::chrono::milliseconds tolerance = bool allowSmaller,
std::chrono::milliseconds(5)); std::chrono::nanoseconds tolerance = std::chrono::milliseconds(5));
} }
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment