Commit 3f09eed1 authored by Aravind Anbudurai's avatar Aravind Anbudurai Committed by Facebook Github Bot 7

Make AutoTimer usable with Closures

Summary:
Currently, AutoTimer works only with FunctionObjects that are default constructible because it constructs Logger each time it needs to log. This diff makes AutoTimer work with closures too. This will help in making AutoTimer more flexible because the user can capture necessary dependencies in the lambda.

This diff also cleans up the constructors on AutoTimer by making it take an
std::string&& instead of Args... that is passed into folly::to<..>. Although
this makes the instantiation a bit harder, the simplicity of constructor seems
worth it.

This also refactors the callsites of setMinLogTime to directly pass the
value into the ctor and changes callsites on fbcode

Reviewed By: yfeldblum

Differential Revision: D3487868

fbshipit-source-id: 52fa1099a5e39b791972cc0d3f678d44ea4ba288
parent 75e5507c
...@@ -16,11 +16,13 @@ ...@@ -16,11 +16,13 @@
#pragma once #pragma once
#include <chrono> #include <chrono>
#include <string>
#include <type_traits>
#include <folly/Conv.h> #include <folly/Conv.h>
#include <folly/Format.h> #include <folly/Format.h>
#include <folly/String.h> #include <folly/String.h>
#include <glog/logging.h> #include <glog/logging.h>
#include <string>
namespace folly { namespace folly {
...@@ -57,36 +59,23 @@ template< ...@@ -57,36 +59,23 @@ template<
class Clock = std::chrono::high_resolution_clock class Clock = std::chrono::high_resolution_clock
> class AutoTimer final { > class AutoTimer final {
public: public:
explicit AutoTimer(StringPiece msg = "") explicit AutoTimer(
: destructionMessage_(msg.str()), std::string&& msg = "",
start_(Clock::now()), double minTimetoLog = 0.0,
minTimeToLog_(0.0) { Logger&& logger = Logger())
} : destructionMessage_(std::move(msg)),
minTimeToLog_(minTimetoLog),
// Automatically generate a log message using to<std::string>. Makes it logger_(std::move(logger)) {}
// easier to do the common case of things like:
// AutoTimer t("Processed ", n, " items"); // It doesn't really make sense to copy AutoTimer
template<typename... Args> // Movable to make sure the helper method for creating an AutoTimer works.
explicit AutoTimer(Args&&... args) AutoTimer(const AutoTimer&) = delete;
: destructionMessage_(to<std::string>(std::forward<Args>(args)...)), AutoTimer(AutoTimer&&) = default;
start_(Clock::now()), AutoTimer& operator=(const AutoTimer&) = delete;
minTimeToLog_(0.0) { AutoTimer& operator=(AutoTimer&&) = default;
}
~AutoTimer() {
// We don't expose this in the constructor because it creates ambiguity with log(destructionMessage_);
// the variadic template constructor.
void setMinTimeToLog(double t) {
minTimeToLog_ = t;
}
// It doesn't really make sense to copy/move an AutoTimer
AutoTimer(const AutoTimer&) = delete;
AutoTimer(AutoTimer&&) = delete;
AutoTimer& operator=(const AutoTimer&) = delete;
AutoTimer& operator=(AutoTimer&&) = delete;
~AutoTimer() {
log(destructionMessage_);
} }
double log(StringPiece msg = "") { double log(StringPiece msg = "") {
...@@ -113,17 +102,29 @@ private: ...@@ -113,17 +102,29 @@ private:
now - start_ now - start_
).count(); ).count();
if (duration >= minTimeToLog_) { if (duration >= minTimeToLog_) {
Logger()(msg, duration); logger_(msg, duration);
} }
start_ = Clock::now(); // Don't measure logging time start_ = Clock::now(); // Don't measure logging time
return duration; return duration;
} }
const std::string destructionMessage_; const std::string destructionMessage_;
std::chrono::time_point<Clock> start_; std::chrono::time_point<Clock> start_ = Clock::now();
double minTimeToLog_; double minTimeToLog_;
Logger logger_;
}; };
template <
class Logger = GoogleLogger<GoogleLoggerStyle::PRETTY>,
class Clock = std::chrono::high_resolution_clock>
auto makeAutoTimer(
std::string&& msg = "",
double minTimeToLog = 0.0,
Logger&& logger = Logger()) {
return AutoTimer<Logger, Clock>(
std::move(msg), minTimeToLog, std::move(logger));
}
template<GoogleLoggerStyle Style> template<GoogleLoggerStyle Style>
struct GoogleLogger final { struct GoogleLogger final {
void operator()(StringPiece msg, double sec) const { void operator()(StringPiece msg, double sec) const {
......
...@@ -43,6 +43,25 @@ struct StubClock { ...@@ -43,6 +43,25 @@ struct StubClock {
int StubClock::t = 0; int StubClock::t = 0;
TEST(TestAutoTimer, HandleBasicClosure) {
auto logger = [](StringPiece msg, double sec) {
return StubLogger()(msg, sec);
};
StubClock::t = 1;
// 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
// when they use a closure. See test case HandleRealTimerClosure
auto timer =
makeAutoTimer<decltype(logger), StubClock>("", 0.0, std::move(logger));
StubClock::t = 3;
timer.log("foo");
ASSERT_EQ("foo", StubLogger::m);
ASSERT_EQ(2, StubLogger::t);
timer.logFormat("bar {}", 5e-2);
ASSERT_EQ("bar 0.05", StubLogger::m);
ASSERT_EQ(0, StubLogger::t);
}
TEST(TestAutoTimer, HandleBasic) { TEST(TestAutoTimer, HandleBasic) {
StubClock::t = 1; StubClock::t = 1;
AutoTimer<StubLogger, StubClock> timer; AutoTimer<StubLogger, StubClock> timer;
...@@ -69,6 +88,15 @@ TEST(TestAutoTimer, HandleLogOnDestruct) { ...@@ -69,6 +88,15 @@ TEST(TestAutoTimer, HandleLogOnDestruct) {
ASSERT_EQ(2, StubLogger::t); ASSERT_EQ(2, StubLogger::t);
} }
TEST(TestAutoTimer, HandleRealTimerClosure) {
auto t = makeAutoTimer(
"Third message on destruction", 0.0, [](StringPiece msg, double sec) {
GoogleLogger<GoogleLoggerStyle::PRETTY>()(msg, sec);
});
t.log("First message");
t.log("Second message");
}
TEST(TestAutoTimer, HandleRealTimer) { TEST(TestAutoTimer, HandleRealTimer) {
AutoTimer<> t("Third message on destruction"); AutoTimer<> t("Third message on destruction");
t.log("First message"); t.log("First message");
...@@ -77,8 +105,7 @@ TEST(TestAutoTimer, HandleRealTimer) { ...@@ -77,8 +105,7 @@ TEST(TestAutoTimer, HandleRealTimer) {
TEST(TestAutoTimer, HandleMinLogTime) { TEST(TestAutoTimer, HandleMinLogTime) {
StubClock::t = 1; StubClock::t = 1;
AutoTimer<StubLogger, StubClock> timer; AutoTimer<StubLogger, StubClock> timer("", 3);
timer.setMinTimeToLog(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;
......
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