1
// Copyright (c) 2009-2010 Satoshi Nakamoto
2
// Copyright (c) 2009-2021 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 <string>
16

            
17

            
18
namespace BCLog {
19

            
20
//! RAII-style object that outputs timing information to logs.
21
template <typename TimeType>
22
class Timer
23
{
24
public:
25
    //! If log_category is left as the default, end_msg will log unconditionally
26
    //! (instead of being filtered by category).
27
    Timer(
28
        std::string prefix,
29
        std::string end_msg,
30
        BCLog::LogFlags log_category = BCLog::LogFlags::ALL,
31
        bool msg_on_completion = true) :
32
            m_prefix(std::move(prefix)),
33
            m_title(std::move(end_msg)),
34
            m_log_category(log_category),
35
            m_message_on_completion(msg_on_completion)
36
    {
37
        this->Log(strprintf("%s started", m_title));
38
        m_start_t = GetTime<std::chrono::microseconds>();
39
    }
40

            
41
    ~Timer()
42
    {
43
        if (m_message_on_completion) {
44
            this->Log(strprintf("%s completed", m_title));
45
        } else {
46
            this->Log("completed");
47
        }
48
    }
49

            
50
    void Log(const std::string& msg)
51
    {
52
        const std::string full_msg = this->LogMsg(msg);
53

            
54
        if (m_log_category == BCLog::LogFlags::ALL) {
55
            LogPrintf("%s\n", full_msg);
56
        } else {
57
            LogPrint(m_log_category, "%s\n", full_msg);
58
        }
59
    }
60

            
61
    std::string LogMsg(const std::string& msg)
62
    {
63
        const auto end_time = GetTime<std::chrono::microseconds>() - m_start_t;
64
        if (m_start_t.count() <= 0) {
65
            return strprintf("%s: %s", m_prefix, msg);
66
        }
67

            
68
        if constexpr (std::is_same<TimeType, std::chrono::microseconds>::value) {
69
            return strprintf("%s: %s (%iμs)", m_prefix, msg, end_time.count());
70
        } else if constexpr (std::is_same<TimeType, std::chrono::milliseconds>::value) {
71
            return strprintf("%s: %s (%.2fms)", m_prefix, msg, end_time.count() * 0.001);
72
        } else if constexpr (std::is_same<TimeType, std::chrono::seconds>::value) {
73
            return strprintf("%s: %s (%.2fs)", m_prefix, msg, end_time.count() * 0.000001);
74
        } else {
75
            static_assert(ALWAYS_FALSE<TimeType>, "Error: unexpected time type");
76
        }
77
    }
78

            
79
private:
80
    std::chrono::microseconds m_start_t{};
81

            
82
    //! Log prefix; usually the name of the function this was created in.
83
    const std::string m_prefix;
84

            
85
    //! A descriptive message of what is being timed.
86
    const std::string m_title;
87

            
88
    //! Forwarded on to LogPrint if specified - has the effect of only
89
    //! outputting the timing log when a particular debug= category is specified.
90
    const BCLog::LogFlags m_log_category;
91

            
92
    //! Whether to output the message again on completion.
93
    const bool m_message_on_completion;
94
};
95

            
96
} // namespace BCLog
97

            
98

            
99
#define LOG_TIME_MICROS_WITH_CATEGORY(end_msg, log_category) \
100
    BCLog::Timer<std::chrono::microseconds> UNIQUE_NAME(logging_timer)(__func__, end_msg, log_category)
101
#define LOG_TIME_MILLIS_WITH_CATEGORY(end_msg, log_category) \
102
    BCLog::Timer<std::chrono::milliseconds> UNIQUE_NAME(logging_timer)(__func__, end_msg, log_category)
103
#define LOG_TIME_MILLIS_WITH_CATEGORY_MSG_ONCE(end_msg, log_category) \
104
    BCLog::Timer<std::chrono::milliseconds> UNIQUE_NAME(logging_timer)(__func__, end_msg, log_category, /* msg_on_completion=*/false)
105
#define LOG_TIME_SECONDS(end_msg) \
106
    BCLog::Timer<std::chrono::seconds> UNIQUE_NAME(logging_timer)(__func__, end_msg)
107

            
108

            
109
#endif // BITCOIN_LOGGING_TIMER_H