Commit f6da18f2 authored by Andrey Goder's avatar Andrey Goder Committed by Noam Lerner

Support 'min ms to log'

Summary:
Sometimes we only want to log if enough time has passed, e.g. when logging
inside of a loop doing work to detect if things are slow. Add an option for
that.

Test Plan:
build and unit tests of folly/experimental

Reviewed By: lesha@fb.com

Subscribers: trunkagent, folly-diffs@, yfeldblum

FB internal diff: D1909055

Signature: t1:1909055:1426627731:6d3ad94fd71967ec89ffebc90cd2907dd1631d36
parent 816b97a7
...@@ -59,7 +59,8 @@ template< ...@@ -59,7 +59,8 @@ template<
public: public:
explicit AutoTimer(StringPiece msg = "") explicit AutoTimer(StringPiece msg = "")
: destructionMessage_(msg.str()), : destructionMessage_(msg.str()),
start_(Clock::now()) { start_(Clock::now()),
minTimeToLog_(0.0) {
} }
// Automatically generate a log message using to<std::string>. Makes it // Automatically generate a log message using to<std::string>. Makes it
...@@ -68,7 +69,14 @@ public: ...@@ -68,7 +69,14 @@ public:
template<typename... Args> template<typename... Args>
explicit AutoTimer(Args&&... args) explicit AutoTimer(Args&&... args)
: destructionMessage_(to<std::string>(std::forward<Args>(args)...)), : destructionMessage_(to<std::string>(std::forward<Args>(args)...)),
start_(Clock::now()) { start_(Clock::now()),
minTimeToLog_(0.0) {
}
// We don't expose this in the constructor because it creates ambiguity with
// the variadic template constructor.
void setMinTimeToLog(double t) {
minTimeToLog_ = t;
} }
// It doesn't really make sense to copy/move an AutoTimer // It doesn't really make sense to copy/move an AutoTimer
...@@ -104,17 +112,20 @@ private: ...@@ -104,17 +112,20 @@ private:
double duration = std::chrono::duration_cast<std::chrono::duration<double>>( double duration = std::chrono::duration_cast<std::chrono::duration<double>>(
now - start_ now - start_
).count(); ).count();
Logger()(msg, duration); if (duration >= minTimeToLog_) {
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_;
double minTimeToLog_;
}; };
template<GoogleLoggerStyle Style> template<GoogleLoggerStyle Style>
struct GoogleLogger { struct GoogleLogger final {
void operator()(StringPiece msg, double sec) const { void operator()(StringPiece msg, double sec) const {
if (msg.empty()) { if (msg.empty()) {
return; return;
......
...@@ -74,3 +74,14 @@ TEST(TestAutoTimer, HandleRealTimer) { ...@@ -74,3 +74,14 @@ TEST(TestAutoTimer, HandleRealTimer) {
t.log("First message"); t.log("First message");
t.log("Second message"); t.log("Second message");
} }
TEST(TestAutoTimer, HandleMinLogTime) {
StubClock::t = 1;
AutoTimer<StubLogger, StubClock> timer;
timer.setMinTimeToLog(3);
StubClock::t = 3;
// only 2 "seconds" have passed, so this shouldn't log
StubLogger::t = 0;
ASSERT_EQ(2.0, timer.log("foo"));
ASSERT_EQ(0, 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