Commit 0b14cc4f authored by Aravind Anbudurai's avatar Aravind Anbudurai Committed by Facebook Github Bot 5

Make AutoTimer work with std::chrono::duration instead of seconds with type double

Summary:
Currently, AutoTimer outputs duration as a double with seconds as units.
This is limiting and I'm making it return std::chrono::duration. Users can specify the type with DurationType.

This is needed for me because the library that I am going to use inside the callback I pass in using chrono::duration and it feels hacky to go from duration -> double -> duration.

Reviewed By: yfeldblum

Differential Revision: D3506557

fbshipit-source-id: 0a5e9e16181bfac3a10df6a253716c0499cff5df
parent ca33aa31
...@@ -45,8 +45,9 @@ struct GoogleLogger; ...@@ -45,8 +45,9 @@ struct GoogleLogger;
* "Foo() completed in 4.3 seconds" * "Foo() completed in 4.3 seconds"
* *
* You can customize what you use as the logger and clock. The logger needs * You can customize what you use as the logger and clock. The logger needs
* to have an operator()(StringPiece, double) that gets a message and a duration * to have an operator()(StringPiece, std::chrono::duration<double>) that
* (in seconds). The clock needs to model Clock from std::chrono. * gets a message and a duration. The clock needs to model Clock from
* std::chrono.
* *
* The default logger logs usings glog. It only logs if the message is * The default logger logs usings glog. It only logs if the message is
* non-empty, so you can also just use this class for timing, e.g.: * non-empty, so you can also just use this class for timing, e.g.:
...@@ -60,9 +61,11 @@ template < ...@@ -60,9 +61,11 @@ template <
class Clock = std::chrono::high_resolution_clock> class Clock = std::chrono::high_resolution_clock>
class AutoTimer final { class AutoTimer final {
public: public:
using DoubleSeconds = std::chrono::duration<double>;
explicit AutoTimer( explicit AutoTimer(
std::string&& msg = "", std::string&& msg = "",
double minTimetoLog = 0.0, const DoubleSeconds& minTimetoLog = DoubleSeconds::zero(),
Logger&& logger = Logger()) Logger&& logger = Logger())
: destructionMessage_(std::move(msg)), : destructionMessage_(std::move(msg)),
minTimeToLog_(minTimetoLog), minTimeToLog_(minTimetoLog),
...@@ -79,18 +82,18 @@ class AutoTimer final { ...@@ -79,18 +82,18 @@ class AutoTimer final {
log(destructionMessage_); log(destructionMessage_);
} }
double log(StringPiece msg = "") { DoubleSeconds log(StringPiece msg = "") {
return logImpl(Clock::now(), msg); return logImpl(Clock::now(), msg);
} }
template <typename... Args> template <typename... Args>
double log(Args&&... args) { DoubleSeconds log(Args&&... args) {
auto now = Clock::now(); auto now = Clock::now();
return logImpl(now, to<std::string>(std::forward<Args>(args)...)); return logImpl(now, to<std::string>(std::forward<Args>(args)...));
} }
template <typename... Args> template <typename... Args>
double logFormat(Args&&... args) { DoubleSeconds logFormat(Args&&... args) {
auto now = Clock::now(); auto now = Clock::now();
return logImpl(now, format(std::forward<Args>(args)...).str()); return logImpl(now, format(std::forward<Args>(args)...).str());
} }
...@@ -98,10 +101,8 @@ class AutoTimer final { ...@@ -98,10 +101,8 @@ class AutoTimer final {
private: private:
// We take in the current time so that we don't measure time to call // We take in the current time so that we don't measure time to call
// to<std::string> or format() in the duration. // to<std::string> or format() in the duration.
double logImpl(std::chrono::time_point<Clock> now, StringPiece msg) { DoubleSeconds logImpl(std::chrono::time_point<Clock> now, StringPiece msg) {
double duration = auto duration = now - start_;
std::chrono::duration_cast<std::chrono::duration<double>>(now - start_)
.count();
if (duration >= minTimeToLog_) { if (duration >= minTimeToLog_) {
logger_(msg, duration); logger_(msg, duration);
} }
...@@ -111,7 +112,7 @@ class AutoTimer final { ...@@ -111,7 +112,7 @@ class AutoTimer final {
const std::string destructionMessage_; const std::string destructionMessage_;
std::chrono::time_point<Clock> start_ = Clock::now(); std::chrono::time_point<Clock> start_ = Clock::now();
double minTimeToLog_; DoubleSeconds minTimeToLog_;
Logger logger_; Logger logger_;
}; };
...@@ -120,7 +121,8 @@ template < ...@@ -120,7 +121,8 @@ template <
class Clock = std::chrono::high_resolution_clock> class Clock = std::chrono::high_resolution_clock>
auto makeAutoTimer( auto makeAutoTimer(
std::string&& msg = "", std::string&& msg = "",
double minTimeToLog = 0.0, const std::chrono::duration<double>& minTimeToLog =
std::chrono::duration<double>::zero(),
Logger&& logger = Logger()) { Logger&& logger = Logger()) {
return AutoTimer<Logger, Clock>( return AutoTimer<Logger, Clock>(
std::move(msg), minTimeToLog, std::move(logger)); std::move(msg), minTimeToLog, std::move(logger));
...@@ -128,14 +130,16 @@ auto makeAutoTimer( ...@@ -128,14 +130,16 @@ auto makeAutoTimer(
template <GoogleLoggerStyle Style> template <GoogleLoggerStyle Style>
struct GoogleLogger final { struct GoogleLogger final {
void operator()(StringPiece msg, double sec) const { void operator()(StringPiece msg, const std::chrono::duration<double>& sec)
const {
if (msg.empty()) { if (msg.empty()) {
return; return;
} }
if (Style == GoogleLoggerStyle::PRETTY) { if (Style == GoogleLoggerStyle::PRETTY) {
LOG(INFO) << msg << " in " << prettyPrint(sec, PrettyType::PRETTY_TIME); LOG(INFO) << msg << " in "
<< prettyPrint(sec.count(), PrettyType::PRETTY_TIME);
} else { } else {
LOG(INFO) << msg << " in " << sec << " seconds"; LOG(INFO) << msg << " in " << sec.count() << " seconds";
} }
} }
}; };
......
...@@ -21,9 +21,9 @@ using namespace folly; ...@@ -21,9 +21,9 @@ using namespace folly;
using namespace std; using namespace std;
struct StubLogger { struct StubLogger {
void operator()(StringPiece msg, double sec) { void operator()(StringPiece msg, std::chrono::duration<double> sec) {
m = msg.str(); m = msg.str();
t = sec; t = sec.count();
} }
static std::string m; static std::string m;
static double t; static double t;
...@@ -44,15 +44,15 @@ struct StubClock { ...@@ -44,15 +44,15 @@ struct StubClock {
int StubClock::t = 0; int StubClock::t = 0;
TEST(TestAutoTimer, HandleBasicClosure) { TEST(TestAutoTimer, HandleBasicClosure) {
auto logger = [](StringPiece msg, double sec) { auto logger = [](StringPiece msg, auto sec) {
return StubLogger()(msg, sec); return StubLogger()(msg, sec);
}; };
StubClock::t = 1; StubClock::t = 1;
// Here decltype is needed. But since most users are expected to use this // Here decltype is needed. But since most users are expected to use this
// method with the default clock, template specification won't be needed even // method with the default clock, template specification won't be needed even
// when they use a closure. See test case HandleRealTimerClosure // when they use a closure. See test case HandleRealTimerClosure
auto timer = auto timer = makeAutoTimer<decltype(logger), StubClock>(
makeAutoTimer<decltype(logger), StubClock>("", 0.0, std::move(logger)); "", std::chrono::duration<double>::zero(), std::move(logger));
StubClock::t = 3; StubClock::t = 3;
timer.log("foo"); timer.log("foo");
ASSERT_EQ("foo", StubLogger::m); ASSERT_EQ("foo", StubLogger::m);
...@@ -90,7 +90,9 @@ TEST(TestAutoTimer, HandleLogOnDestruct) { ...@@ -90,7 +90,9 @@ TEST(TestAutoTimer, HandleLogOnDestruct) {
TEST(TestAutoTimer, HandleRealTimerClosure) { TEST(TestAutoTimer, HandleRealTimerClosure) {
auto t = makeAutoTimer( auto t = makeAutoTimer(
"Third message on destruction", 0.0, [](StringPiece msg, double sec) { "Third message on destruction",
std::chrono::duration<double>::zero(),
[](StringPiece msg, auto sec) {
GoogleLogger<GoogleLoggerStyle::PRETTY>()(msg, sec); GoogleLogger<GoogleLoggerStyle::PRETTY>()(msg, sec);
}); });
t.log("First message"); t.log("First message");
...@@ -105,10 +107,10 @@ TEST(TestAutoTimer, HandleRealTimer) { ...@@ -105,10 +107,10 @@ TEST(TestAutoTimer, HandleRealTimer) {
TEST(TestAutoTimer, HandleMinLogTime) { TEST(TestAutoTimer, HandleMinLogTime) {
StubClock::t = 1; StubClock::t = 1;
AutoTimer<StubLogger, StubClock> timer("", 3); AutoTimer<StubLogger, StubClock> timer("", std::chrono::duration<double>(3));
StubClock::t = 3; StubClock::t = 3;
// only 2 "seconds" have passed, so this shouldn't log // only 2 "seconds" have passed, so this shouldn't log
StubLogger::t = 0; StubLogger::t = 0;
ASSERT_EQ(2.0, timer.log("foo")); ASSERT_EQ(std::chrono::duration<double>(2), timer.log("foo"));
ASSERT_EQ(0, StubLogger::t); ASSERT_EQ(std::chrono::duration<double>::zero().count(), StubLogger::t);
} }
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