1 // Copyright (c) 2009-2010 Satoshi Nakamoto
2 // Copyright (c) 2009-2019 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     Timer(
27         std::string prefix,
28         std::string end_msg,
29         BCLog::LogFlags log_category = BCLog::LogFlags::ALL) :
m_prefix(std::move (prefix))30             m_prefix(std::move(prefix)),
31             m_title(std::move(end_msg)),
32             m_log_category(log_category)
33     {
34         this->Log(strprintf("%s started", m_title));
35         m_start_t = GetTime<std::chrono::microseconds>();
36     }
37 
~Timer()38     ~Timer()
39     {
40         this->Log(strprintf("%s completed", m_title));
41     }
42 
Log(const std::string & msg)43     void Log(const std::string& msg)
44     {
45         const std::string full_msg = this->LogMsg(msg);
46 
47         if (m_log_category == BCLog::LogFlags::ALL) {
48             LogPrintf("%s\n", full_msg);
49         } else {
50             LogPrint(m_log_category, "%s\n", full_msg);
51         }
52     }
53 
LogMsg(const std::string & msg)54     std::string LogMsg(const std::string& msg)
55     {
56         const auto end_time = GetTime<std::chrono::microseconds>() - m_start_t;
57         if (m_start_t.count() <= 0) {
58             return strprintf("%s: %s", m_prefix, msg);
59         }
60 
61         std::string units = "";
62         float divisor = 1;
63 
64         if (std::is_same<TimeType, std::chrono::microseconds>::value) {
65             units = "μs";
66         } else if (std::is_same<TimeType, std::chrono::milliseconds>::value) {
67             units = "ms";
68             divisor = 1000.;
69         } else if (std::is_same<TimeType, std::chrono::seconds>::value) {
70             units = "s";
71             divisor = 1000. * 1000.;
72         }
73 
74         const float time_ms = end_time.count() / divisor;
75         return strprintf("%s: %s (%.2f%s)", m_prefix, msg, time_ms, units);
76     }
77 
78 private:
79     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_MICROS(end_msg, ...) \
97     BCLog::Timer<std::chrono::microseconds> PASTE2(logging_timer, __COUNTER__)(__func__, end_msg, ## __VA_ARGS__)
98 #define LOG_TIME_MILLIS(end_msg, ...) \
99     BCLog::Timer<std::chrono::milliseconds> PASTE2(logging_timer, __COUNTER__)(__func__, end_msg, ## __VA_ARGS__)
100 #define LOG_TIME_SECONDS(end_msg, ...) \
101     BCLog::Timer<std::chrono::seconds> PASTE2(logging_timer, __COUNTER__)(__func__, end_msg, ## __VA_ARGS__)
102 
103 
104 #endif // BITCOIN_LOGGING_TIMER_H
105