From 3f09eed1c170722897cfb988bf0702c35b67b2ec Mon Sep 17 00:00:00 2001 From: Aravind Anbudurai Date: Thu, 30 Jun 2016 00:48:22 -0700 Subject: [PATCH] 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 --- folly/experimental/AutoTimer.h | 67 ++++++++++++----------- folly/experimental/test/AutoTimerTest.cpp | 31 ++++++++++- 2 files changed, 63 insertions(+), 35 deletions(-) diff --git a/folly/experimental/AutoTimer.h b/folly/experimental/AutoTimer.h index 39b5b2ae..7e0f2909 100644 --- a/folly/experimental/AutoTimer.h +++ b/folly/experimental/AutoTimer.h @@ -16,11 +16,13 @@ #pragma once #include +#include +#include + #include #include #include #include -#include namespace folly { @@ -57,36 +59,23 @@ template< class Clock = std::chrono::high_resolution_clock > class AutoTimer final { public: - explicit AutoTimer(StringPiece msg = "") - : destructionMessage_(msg.str()), - start_(Clock::now()), - minTimeToLog_(0.0) { - } - - // Automatically generate a log message using to. Makes it - // easier to do the common case of things like: - // AutoTimer t("Processed ", n, " items"); - template - explicit AutoTimer(Args&&... args) - : destructionMessage_(to(std::forward(args)...)), - 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 - AutoTimer(const AutoTimer&) = delete; - AutoTimer(AutoTimer&&) = delete; - AutoTimer& operator=(const AutoTimer&) = delete; - AutoTimer& operator=(AutoTimer&&) = delete; - - ~AutoTimer() { - log(destructionMessage_); + explicit AutoTimer( + std::string&& msg = "", + double minTimetoLog = 0.0, + Logger&& logger = Logger()) + : destructionMessage_(std::move(msg)), + minTimeToLog_(minTimetoLog), + logger_(std::move(logger)) {} + + // It doesn't really make sense to copy AutoTimer + // Movable to make sure the helper method for creating an AutoTimer works. + AutoTimer(const AutoTimer&) = delete; + AutoTimer(AutoTimer&&) = default; + AutoTimer& operator=(const AutoTimer&) = delete; + AutoTimer& operator=(AutoTimer&&) = default; + + ~AutoTimer() { + log(destructionMessage_); } double log(StringPiece msg = "") { @@ -113,17 +102,29 @@ private: now - start_ ).count(); if (duration >= minTimeToLog_) { - Logger()(msg, duration); + logger_(msg, duration); } start_ = Clock::now(); // Don't measure logging time return duration; } const std::string destructionMessage_; - std::chrono::time_point start_; + std::chrono::time_point start_ = Clock::now(); double minTimeToLog_; + Logger logger_; }; +template < + class Logger = GoogleLogger, + class Clock = std::chrono::high_resolution_clock> +auto makeAutoTimer( + std::string&& msg = "", + double minTimeToLog = 0.0, + Logger&& logger = Logger()) { + return AutoTimer( + std::move(msg), minTimeToLog, std::move(logger)); +} + template struct GoogleLogger final { void operator()(StringPiece msg, double sec) const { diff --git a/folly/experimental/test/AutoTimerTest.cpp b/folly/experimental/test/AutoTimerTest.cpp index 7a08aa77..9fb47a3d 100644 --- a/folly/experimental/test/AutoTimerTest.cpp +++ b/folly/experimental/test/AutoTimerTest.cpp @@ -43,6 +43,25 @@ struct StubClock { 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("", 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) { StubClock::t = 1; AutoTimer timer; @@ -69,6 +88,15 @@ TEST(TestAutoTimer, HandleLogOnDestruct) { ASSERT_EQ(2, StubLogger::t); } +TEST(TestAutoTimer, HandleRealTimerClosure) { + auto t = makeAutoTimer( + "Third message on destruction", 0.0, [](StringPiece msg, double sec) { + GoogleLogger()(msg, sec); + }); + t.log("First message"); + t.log("Second message"); +} + TEST(TestAutoTimer, HandleRealTimer) { AutoTimer<> t("Third message on destruction"); t.log("First message"); @@ -77,8 +105,7 @@ TEST(TestAutoTimer, HandleRealTimer) { TEST(TestAutoTimer, HandleMinLogTime) { StubClock::t = 1; - AutoTimer timer; - timer.setMinTimeToLog(3); + AutoTimer timer("", 3); StubClock::t = 3; // only 2 "seconds" have passed, so this shouldn't log StubLogger::t = 0; -- 2.34.1