folly/experimental/AutoTimer.h

   1 /*
   2  * Copyright 2016 Facebook, Inc.
   3  *
   4  * Licensed under the Apache License, Version 2.0 (the "License");
   5  * you may not use this file except in compliance with the License.
   6  * You may obtain a copy of the License at
   7  *
   8  *   http://www.apache.org/licenses/LICENSE-2.0
   9  *
  10  * Unless required by applicable law or agreed to in writing, software
  11  * distributed under the License is distributed on an "AS IS" BASIS,
  12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13  * See the License for the specific language governing permissions and
  14  * limitations under the License.
  15  */
  16 #pragma once
  17
  18 #include <chrono>
  19 #include <string>
  20 #include <type_traits>
  21
  22 #include <folly/Conv.h>
  23 #include <folly/Format.h>
  24 #include <folly/String.h>
  25 #include <glog/logging.h>
  26
  27 namespace folly {
  28
  29 // Default logger
  30 enum class GoogleLoggerStyle { SECONDS, PRETTY };
  31 template <GoogleLoggerStyle>
  32 struct GoogleLogger;
  33
  34 /**
  35  * Automatically times a block of code, printing a specified log message on
  36  * destruction or whenever the log() method is called. For example:
  37  *
  38  *   AutoTimer t("Foo() completed");
  39  *   doWork();
  40  *   t.log("Do work finished");
  41  *   doMoreWork();
  42  *
  43  * This would print something like:
  44  *   "Do work finished in 1.2 seconds"
  45  *   "Foo() completed in 4.3 seconds"
  46  *
  47  * You can customize what you use as the logger and clock. The logger needs
  48  * to have an operator()(StringPiece, double) that gets a message and a duration
  49  * (in seconds). The clock needs to model Clock from std::chrono.
  50  *
  51  * The default logger logs usings glog. It only logs if the message is
  52  * non-empty, so you can also just use this class for timing, e.g.:
  53  *
  54  *   AutoTimer t;
  55  *   doWork()
  56  *   const auto how_long = t.log();
  57  */
  58 template <
  59     class Logger = GoogleLogger<GoogleLoggerStyle::PRETTY>,
  60     class Clock = std::chrono::high_resolution_clock>
  61 class AutoTimer final {
  62  public:
  63   explicit AutoTimer(
  64       std::string&& msg = "",
  65       double minTimetoLog = 0.0,
  66       Logger&& logger = Logger())
  67       : destructionMessage_(std::move(msg)),
  68         minTimeToLog_(minTimetoLog),
  69         logger_(std::move(logger)) {}
  70
  71   // It doesn't really make sense to copy AutoTimer
  72   // Movable to make sure the helper method for creating an AutoTimer works.
  73   AutoTimer(const AutoTimer&) = delete;
  74   AutoTimer(AutoTimer&&) = default;
  75   AutoTimer& operator=(const AutoTimer&) = delete;
  76   AutoTimer& operator=(AutoTimer&&) = default;
  77
  78   ~AutoTimer() {
  79     log(destructionMessage_);
  80   }
  81
  82   double log(StringPiece msg = "") {
  83     return logImpl(Clock::now(), msg);
  84   }
  85
  86   template <typename... Args>
  87   double log(Args&&... args) {
  88     auto now = Clock::now();
  89     return logImpl(now, to<std::string>(std::forward<Args>(args)...));
  90   }
  91
  92   template <typename... Args>
  93   double logFormat(Args&&... args) {
  94     auto now = Clock::now();
  95     return logImpl(now, format(std::forward<Args>(args)...).str());
  96   }
  97
  98  private:
  99   // We take in the current time so that we don't measure time to call
 100   // to<std::string> or format() in the duration.
 101   double logImpl(std::chrono::time_point<Clock> now, StringPiece msg) {
 102     double duration =
 103         std::chrono::duration_cast<std::chrono::duration<double>>(now - start_)
 104             .count();
 105     if (duration >= minTimeToLog_) {
 106       logger_(msg, duration);
 107     }
 108     start_ = Clock::now(); // Don't measure logging time
 109     return duration;
 110   }
 111
 112   const std::string destructionMessage_;
 113   std::chrono::time_point<Clock> start_ = Clock::now();
 114   double minTimeToLog_;
 115   Logger logger_;
 116 };
 117
 118 template <
 119     class Logger = GoogleLogger<GoogleLoggerStyle::PRETTY>,
 120     class Clock = std::chrono::high_resolution_clock>
 121 auto makeAutoTimer(
 122     std::string&& msg = "",
 123     double minTimeToLog = 0.0,
 124     Logger&& logger = Logger()) {
 125   return AutoTimer<Logger, Clock>(
 126       std::move(msg), minTimeToLog, std::move(logger));
 127 }
 128
 129 template <GoogleLoggerStyle Style>
 130 struct GoogleLogger final {
 131   void operator()(StringPiece msg, double sec) const {
 132     if (msg.empty()) {
 133       return;
 134     }
 135     if (Style == GoogleLoggerStyle::PRETTY) {
 136       LOG(INFO) << msg << " in " << prettyPrint(sec, PrettyType::PRETTY_TIME);
 137     } else {
 138       LOG(INFO) << msg << " in " << sec << " seconds";
 139     }
 140   }
 141 };
 142 }