folly/experimental/AutoTimer.h

   1 /*
   2  * Copyright 2017 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/Optional.h>
  25 #include <folly/String.h>
  26 #include <glog/logging.h>
  27
  28 namespace folly {
  29
  30 // Default logger
  31 enum class GoogleLoggerStyle { SECONDS, PRETTY };
  32 template <GoogleLoggerStyle>
  33 struct GoogleLogger;
  34
  35 /**
  36  * Automatically times a block of code, printing a specified log message on
  37  * destruction or whenever the log() method is called. For example:
  38  *
  39  *   AutoTimer t("Foo() completed");
  40  *   doWork();
  41  *   t.log("Do work finished");
  42  *   doMoreWork();
  43  *
  44  * This would print something like:
  45  *   "Do work finished in 1.2 seconds"
  46  *   "Foo() completed in 4.3 seconds"
  47  *
  48  * You can customize what you use as the logger and clock. The logger needs
  49  * to have an operator()(StringPiece, std::chrono::duration<double>) that
  50  * gets a message and a duration. The clock needs to model Clock from
  51  * std::chrono.
  52  *
  53  * The default logger logs usings glog. It only logs if the message is
  54  * non-empty, so you can also just use this class for timing, e.g.:
  55  *
  56  *   AutoTimer t;
  57  *   doWork()
  58  *   const auto how_long = t.log();
  59  */
  60 template <
  61     class Logger = GoogleLogger<GoogleLoggerStyle::PRETTY>,
  62     class Clock = std::chrono::high_resolution_clock>
  63 class AutoTimer final {
  64  public:
  65   using DoubleSeconds = std::chrono::duration<double>;
  66
  67   explicit AutoTimer(
  68       std::string&& msg = "",
  69       const DoubleSeconds& minTimetoLog = DoubleSeconds::zero(),
  70       Logger&& logger = Logger())
  71       : destructionMessage_(std::move(msg)),
  72         minTimeToLog_(minTimetoLog),
  73         logger_(std::move(logger)) {}
  74
  75   // It doesn't really make sense to copy AutoTimer
  76   // Movable to make sure the helper method for creating an AutoTimer works.
  77   AutoTimer(const AutoTimer&) = delete;
  78   AutoTimer(AutoTimer&&) = default;
  79   AutoTimer& operator=(const AutoTimer&) = delete;
  80   AutoTimer& operator=(AutoTimer&&) = default;
  81
  82   ~AutoTimer() {
  83     if (destructionMessage_) {
  84       log(destructionMessage_.value());
  85     }
  86   }
  87
  88   DoubleSeconds log(StringPiece msg = "") {
  89     return logImpl(Clock::now(), msg);
  90   }
  91
  92   template <typename... Args>
  93   DoubleSeconds log(Args&&... args) {
  94     auto now = Clock::now();
  95     return logImpl(now, to<std::string>(std::forward<Args>(args)...));
  96   }
  97
  98   template <typename... Args>
  99   DoubleSeconds logFormat(Args&&... args) {
 100     auto now = Clock::now();
 101     return logImpl(now, format(std::forward<Args>(args)...).str());
 102   }
 103
 104  private:
 105   // We take in the current time so that we don't measure time to call
 106   // to<std::string> or format() in the duration.
 107   DoubleSeconds logImpl(std::chrono::time_point<Clock> now, StringPiece msg) {
 108     auto duration = now - start_;
 109     if (duration >= minTimeToLog_) {
 110       logger_(msg, duration);
 111     }
 112     start_ = Clock::now(); // Don't measure logging time
 113     return duration;
 114   }
 115
 116   Optional<std::string> destructionMessage_;
 117   std::chrono::time_point<Clock> start_ = Clock::now();
 118   DoubleSeconds minTimeToLog_;
 119   Logger logger_;
 120 };
 121
 122 template <
 123     class Logger = GoogleLogger<GoogleLoggerStyle::PRETTY>,
 124     class Clock = std::chrono::high_resolution_clock>
 125 auto makeAutoTimer(
 126     std::string&& msg = "",
 127     const std::chrono::duration<double>& minTimeToLog =
 128         std::chrono::duration<double>::zero(),
 129     Logger&& logger = Logger()) {
 130   return AutoTimer<Logger, Clock>(
 131       std::move(msg), minTimeToLog, std::move(logger));
 132 }
 133
 134 template <GoogleLoggerStyle Style>
 135 struct GoogleLogger final {
 136   void operator()(StringPiece msg, const std::chrono::duration<double>& sec)
 137       const {
 138     if (msg.empty()) {
 139       return;
 140     }
 141     if (Style == GoogleLoggerStyle::PRETTY) {
 142       LOG(INFO) << msg << " in "
 143                 << prettyPrint(sec.count(), PrettyType::PRETTY_TIME);
 144     } else {
 145       LOG(INFO) << msg << " in " << sec.count() << " seconds";
 146     }
 147   }
 148 };
 149 } // namespace folly