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