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

diff --git a/folly/experimental/AutoTimer.h b/folly/experimental/AutoTimer.h
index 39b5b2ae495c398d8f1c59c3d7e98aedb015d8f5..7e0f2909afece6e4594c83acabdbd32b24890e1c 100644 (file)
--- a/folly/experimental/AutoTimer.h
+++ b/folly/experimental/AutoTimer.h
@@ -16,11 +16,13 @@
 #pragma once
 
 #include <chrono>
+#include <string>
+#include <type_traits>
+
 #include <folly/Conv.h>
 #include <folly/Format.h>
 #include <folly/String.h>
 #include <glog/logging.h>
-#include <string>
 
 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<std::string>. Makes it
-  // easier to do the common case of things like:
-  // AutoTimer t("Processed ", n, " items");
-  template<typename... Args>
-  explicit AutoTimer(Args&&... args)
-    : destructionMessage_(to<std::string>(std::forward<Args>(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<Clock> start_;
+  std::chrono::time_point<Clock> start_ = Clock::now();
   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>
 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 7a08aa774856766d57b1a8bd374f8512408ec007..9fb47a3d9b28979420da1bc7723a838eb034273a 100644 (file)
--- 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<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) {
   StubClock::t = 1;
   AutoTimer<StubLogger, StubClock> 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<GoogleLoggerStyle::PRETTY>()(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<StubLogger, StubClock> timer;
-  timer.setMinTimeToLog(3);
+  AutoTimer<StubLogger, StubClock> timer("", 3);
   StubClock::t = 3;
   // only 2 "seconds" have passed, so this shouldn't log
   StubLogger::t = 0;