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 : 0 : 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 : 0 : : m_prefix(std::move(prefix)),
34 : 0 : m_title(std::move(end_msg)),
35 : 0 : m_log_category(log_category),
36 : 0 : m_message_on_completion(msg_on_completion)
37 : : {
38 [ # # ][ # # ]: 0 : this->Log(strprintf("%s started", m_title));
39 : 0 : m_start_t = std::chrono::steady_clock::now();
40 : 0 : }
41 : :
42 : 0 : ~Timer()
43 : : {
44 [ # # ]: 0 : if (m_message_on_completion) {
45 [ # # ][ # # ]: 0 : this->Log(strprintf("%s completed", m_title));
46 : 0 : } else {
47 [ # # ][ # # ]: 0 : this->Log("completed");
48 : : }
49 : 0 : }
50 : :
51 : 0 : void Log(const std::string& msg)
52 : : {
53 : 0 : const std::string full_msg = this->LogMsg(msg);
54 : :
55 [ # # ]: 0 : if (m_log_category == BCLog::LogFlags::ALL) {
56 [ # # ][ # # ]: 0 : LogPrintf("%s\n", full_msg);
[ # # ]
57 : 0 : } else {
58 [ # # ][ # # ]: 0 : LogPrint(m_log_category, "%s\n", full_msg);
[ # # ][ # # ]
[ # # ]
59 : : }
60 : 0 : }
61 : :
62 : 0 : std::string LogMsg(const std::string& msg)
63 : : {
64 : 0 : const auto end_time{std::chrono::steady_clock::now()};
65 [ # # ]: 0 : if (!m_start_t) {
66 : 0 : return strprintf("%s: %s", m_prefix, msg);
67 : : }
68 : 0 : 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 : 0 : 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 : 0 : }
80 : :
81 : : private:
82 : 0 : 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
|