Line data    Source code

       1             : // Copyright (c) 2009-2010 Satoshi Nakamoto
       2             : // Copyright (c) 2009-2020 The Bitcoin Core developers
       3             : // Distributed under the MIT software license, see the accompanying
       4             : // file COPYING or http://www.opensource.org/licenses/mit-license.php.
       5             : 
       6             : #ifndef BITCOIN_LOGGING_TIMER_H
       7             : #define BITCOIN_LOGGING_TIMER_H
       8             : 
       9             : #include <logging.h>
      10             : #include <util/macros.h>
      11             : #include <util/time.h>
      12             : 
      13             : #include <chrono>
      14             : #include <string>
      15             : 
      16             : 
      17             : namespace BCLog {
      18             : 
      19             : //! RAII-style object that outputs timing information to logs.
      20             : template <typename TimeType>
      21             : class Timer
      22             : {
      23             : public:
      24             :     //! If log_category is left as the default, end_msg will log unconditionally
      25             :     //! (instead of being filtered by category).
      26        8158 :     Timer(
      27             :         std::string prefix,
      28             :         std::string end_msg,
      29             :         BCLog::LogFlags log_category = BCLog::LogFlags::ALL) :
      30        4079 :             m_prefix(std::move(prefix)),
      31        4079 :             m_title(std::move(end_msg)),
      32        4079 :             m_log_category(log_category)
      33        4079 :     {
      34        4079 :         this->Log(strprintf("%s started", m_title));
      35        4079 :         m_start_t = GetTime<std::chrono::microseconds>();
      36        8158 :     }
      37             : 
      38        8158 :     ~Timer()
      39        4079 :     {
      40        4079 :         this->Log(strprintf("%s completed", m_title));
      41        8158 :     }
      42             : 
      43        8158 :     void Log(const std::string& msg)
      44             :     {
      45        8158 :         const std::string full_msg = this->LogMsg(msg);
      46             : 
      47        8158 :         if (m_log_category == BCLog::LogFlags::ALL) {
      48        2706 :             LogPrintf("%s\n", full_msg);
      49             :         } else {
      50        5452 :             LogPrint(m_log_category, "%s\n", full_msg);
      51             :         }
      52        8158 :     }
      53             : 
      54        8161 :     std::string LogMsg(const std::string& msg)
      55             :     {
      56        8161 :         const auto end_time = GetTime<std::chrono::microseconds>() - m_start_t;
      57        8161 :         if (m_start_t.count() <= 0) {
      58        4079 :             return strprintf("%s: %s", m_prefix, msg);
      59             :         }
      60             : 
      61        4082 :         std::string units = "";
      62             :         float divisor = 1;
      63             : 
      64             :         if (std::is_same<TimeType, std::chrono::microseconds>::value) {
      65           2 :             units = "μs";
      66             :         } else if (std::is_same<TimeType, std::chrono::milliseconds>::value) {
      67        2728 :             units = "ms";
      68             :             divisor = 1000.;
      69             :         } else if (std::is_same<TimeType, std::chrono::seconds>::value) {
      70        1352 :             units = "s";
      71             :             divisor = 1000. * 1000.;
      72             :         }
      73             : 
      74        4082 :         const float time_ms = end_time.count() / divisor;
      75        4082 :         return strprintf("%s: %s (%.2f%s)", m_prefix, msg, time_ms, units);
      76        8161 :     }
      77             : 
      78             : private:
      79        4079 :     std::chrono::microseconds m_start_t{};
      80             : 
      81             :     //! Log prefix; usually the name of the function this was created in.
      82             :     const std::string m_prefix{};
      83             : 
      84             :     //! A descriptive message of what is being timed.
      85             :     const std::string m_title{};
      86             : 
      87             :     //! Forwarded on to LogPrint if specified - has the effect of only
      88             :     //! outputting the timing log when a particular debug= category is specified.
      89             :     const BCLog::LogFlags m_log_category{};
      90             : 
      91             : };
      92             : 
      93             : } // namespace BCLog
      94             : 
      95             : 
      96             : #define LOG_TIME_MILLIS_WITH_CATEGORY(end_msg, log_category) \
      97             :     BCLog::Timer<std::chrono::milliseconds> PASTE2(logging_timer, __COUNTER__)(__func__, end_msg, log_category)
      98             : #define LOG_TIME_SECONDS(end_msg) \
      99             :     BCLog::Timer<std::chrono::seconds> PASTE2(logging_timer, __COUNTER__)(__func__, end_msg)
     100             : 
     101             : 
     102             : #endif // BITCOIN_LOGGING_TIMER_H