Branch data     Line data    Source code

       1                 :            : // Copyright (c) 2009-2010 Satoshi Nakamoto
       2                 :            : // Copyright (c) 2009-2022 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                 :            : #include <util/types.h>
      13                 :            : 
      14                 :            : #include <chrono>
      15                 :            : #include <optional>
      16                 :            : #include <string>
      17                 :            : 
      18                 :            : 
      19                 :            : namespace BCLog {
      20                 :            : 
      21                 :            : //! RAII-style object that outputs timing information to logs.
      22                 :            : template <typename TimeType>
      23                 :            : class Timer
      24                 :            : {
      25                 :            : public:
      26                 :            :     //! If log_category is left as the default, end_msg will log unconditionally
      27                 :            :     //! (instead of being filtered by category).
      28                 :     151029 :     Timer(
      29                 :            :         std::string prefix,
      30                 :            :         std::string end_msg,
      31                 :            :         BCLog::LogFlags log_category = BCLog::LogFlags::ALL,
      32                 :            :         bool msg_on_completion = true)
      33                 :     151029 :         : m_prefix(std::move(prefix)),
      34                 :     151029 :           m_title(std::move(end_msg)),
      35                 :     151029 :           m_log_category(log_category),
      36                 :     151029 :           m_message_on_completion(msg_on_completion)
      37                 :            :     {
      38   [ +  -  +  - ]:     151029 :         this->Log(strprintf("%s started", m_title));
      39         [ +  - ]:     151029 :         m_start_t = std::chrono::steady_clock::now();
      40                 :     151029 :     }
      41                 :            : 
      42                 :     151029 :     ~Timer()
      43                 :            :     {
      44         [ +  + ]:     151029 :         if (m_message_on_completion) {
      45   [ +  -  +  - ]:     150108 :             this->Log(strprintf("%s completed", m_title));
      46                 :     150108 :         } else {
      47   [ +  -  +  - ]:        921 :             this->Log("completed");
      48                 :            :         }
      49                 :     151029 :     }
      50                 :            : 
      51                 :     302058 :     void Log(const std::string& msg)
      52                 :            :     {
      53                 :     302058 :         const std::string full_msg = this->LogMsg(msg);
      54                 :            : 
      55         [ +  - ]:     302058 :         if (m_log_category == BCLog::LogFlags::ALL) {
      56   [ #  #  #  #  :          0 :             LogPrintf("%s\n", full_msg);
                   #  # ]
      57                 :          0 :         } else {
      58   [ +  -  +  +  :     302058 :             LogPrint(m_log_category, "%s\n", full_msg);
          +  -  +  -  -  
                      + ]
      59                 :            :         }
      60                 :     302058 :     }
      61                 :            : 
      62                 :     302058 :     std::string LogMsg(const std::string& msg)
      63                 :            :     {
      64                 :     302058 :         const auto end_time{std::chrono::steady_clock::now()};
      65         [ +  + ]:     302058 :         if (!m_start_t) {
      66                 :     151029 :             return strprintf("%s: %s", m_prefix, msg);
      67                 :            :         }
      68                 :     151029 :         const auto duration{end_time - *m_start_t};
      69                 :            : 
      70                 :            :         if constexpr (std::is_same<TimeType, std::chrono::microseconds>::value) {
      71                 :            :             return strprintf("%s: %s (%iμs)", m_prefix, msg, Ticks<std::chrono::microseconds>(duration));
      72                 :            :         } else if constexpr (std::is_same<TimeType, std::chrono::milliseconds>::value) {
      73                 :     151029 :             return strprintf("%s: %s (%.2fms)", m_prefix, msg, Ticks<MillisecondsDouble>(duration));
      74                 :            :         } else if constexpr (std::is_same<TimeType, std::chrono::seconds>::value) {
      75                 :          0 :             return strprintf("%s: %s (%.2fs)", m_prefix, msg, Ticks<SecondsDouble>(duration));
      76                 :            :         } else {
      77                 :            :             static_assert(ALWAYS_FALSE<TimeType>, "Error: unexpected time type");
      78                 :            :         }
      79                 :     302058 :     }
      80                 :            : 
      81                 :            : private:
      82                 :     151029 :     std::optional<std::chrono::steady_clock::time_point> m_start_t{};
      83                 :            : 
      84                 :            :     //! Log prefix; usually the name of the function this was created in.
      85                 :            :     const std::string m_prefix;
      86                 :            : 
      87                 :            :     //! A descriptive message of what is being timed.
      88                 :            :     const std::string m_title;
      89                 :            : 
      90                 :            :     //! Forwarded on to LogPrint if specified - has the effect of only
      91                 :            :     //! outputting the timing log when a particular debug= category is specified.
      92                 :            :     const BCLog::LogFlags m_log_category;
      93                 :            : 
      94                 :            :     //! Whether to output the message again on completion.
      95                 :            :     const bool m_message_on_completion;
      96                 :            : };
      97                 :            : 
      98                 :            : } // namespace BCLog
      99                 :            : 
     100                 :            : 
     101                 :            : #define LOG_TIME_MICROS_WITH_CATEGORY(end_msg, log_category) \
     102                 :            :     BCLog::Timer<std::chrono::microseconds> UNIQUE_NAME(logging_timer)(__func__, end_msg, log_category)
     103                 :            : #define LOG_TIME_MILLIS_WITH_CATEGORY(end_msg, log_category) \
     104                 :            :     BCLog::Timer<std::chrono::milliseconds> UNIQUE_NAME(logging_timer)(__func__, end_msg, log_category)
     105                 :            : #define LOG_TIME_MILLIS_WITH_CATEGORY_MSG_ONCE(end_msg, log_category) \
     106                 :            :     BCLog::Timer<std::chrono::milliseconds> UNIQUE_NAME(logging_timer)(__func__, end_msg, log_category, /* msg_on_completion=*/false)
     107                 :            : #define LOG_TIME_SECONDS(end_msg) \
     108                 :            :     BCLog::Timer<std::chrono::seconds> UNIQUE_NAME(logging_timer)(__func__, end_msg)
     109                 :            : 
     110                 :            : 
     111                 :            : #endif // BITCOIN_LOGGING_TIMER_H