diff options
Diffstat (limited to 'src')
| -rw-r--r-- | src/Makefile.am | 1 | ||||
| -rw-r--r-- | src/Makefile.test.include | 1 | ||||
| -rw-r--r-- | src/logging/timer.h | 104 | ||||
| -rw-r--r-- | src/test/logging_tests.cpp | 36 |
4 files changed, 142 insertions, 0 deletions
diff --git a/src/Makefile.am b/src/Makefile.am index 7af04148cc..798fab1b02 100644 --- a/src/Makefile.am +++ b/src/Makefile.am @@ -146,6 +146,7 @@ BITCOIN_CORE_H = \ dbwrapper.h \ limitedmap.h \ logging.h \ + logging/timer.h \ memusage.h \ merkleblock.h \ miner.h \ diff --git a/src/Makefile.test.include b/src/Makefile.test.include index d3fe138133..8a0fa1bdc5 100644 --- a/src/Makefile.test.include +++ b/src/Makefile.test.include @@ -110,6 +110,7 @@ BITCOIN_TESTS =\ test/key_io_tests.cpp \ test/key_tests.cpp \ test/limitedmap_tests.cpp \ + test/logging_tests.cpp \ test/dbwrapper_tests.cpp \ test/validation_tests.cpp \ test/mempool_tests.cpp \ diff --git a/src/logging/timer.h b/src/logging/timer.h new file mode 100644 index 0000000000..34dbb942c5 --- /dev/null +++ b/src/logging/timer.h @@ -0,0 +1,104 @@ +// Copyright (c) 2009-2010 Satoshi Nakamoto +// Copyright (c) 2009-2018 The Bitcoin Core developers +// Distributed under the MIT software license, see the accompanying +// file COPYING or http://www.opensource.org/licenses/mit-license.php. + +#ifndef BITCOIN_LOGGING_TIMER_H +#define BITCOIN_LOGGING_TIMER_H + +#include <logging.h> +#include <util/macros.h> +#include <util/time.h> + +#include <chrono> +#include <string> + + +namespace BCLog { + +//! RAII-style object that outputs timing information to logs. +template <typename TimeType> +class Timer +{ +public: + //! If log_category is left as the default, end_msg will log unconditionally + //! (instead of being filtered by category). + Timer( + std::string prefix, + std::string end_msg, + BCLog::LogFlags log_category = BCLog::LogFlags::ALL) : + m_prefix(std::move(prefix)), + m_title(std::move(end_msg)), + m_log_category(log_category) + { + this->Log(strprintf("%s started", m_title)); + m_start_t = GetTime<std::chrono::microseconds>(); + } + + ~Timer() + { + this->Log(strprintf("%s completed", m_title)); + } + + void Log(const std::string& msg) + { + const std::string full_msg = this->LogMsg(msg); + + if (m_log_category == BCLog::LogFlags::ALL) { + LogPrintf("%s\n", full_msg); + } else { + LogPrint(m_log_category, "%s\n", full_msg); + } + } + + std::string LogMsg(const std::string& msg) + { + const auto end_time = GetTime<std::chrono::microseconds>() - m_start_t; + if (m_start_t.count() <= 0) { + return strprintf("%s: %s", m_prefix, msg); + } + + std::string units = ""; + float divisor = 1; + + if (std::is_same<TimeType, std::chrono::microseconds>::value) { + units = "μs"; + } else if (std::is_same<TimeType, std::chrono::milliseconds>::value) { + units = "ms"; + divisor = 1000.; + } else if (std::is_same<TimeType, std::chrono::seconds>::value) { + units = "s"; + divisor = 1000. * 1000.; + } + + const float time_ms = end_time.count() / divisor; + return strprintf("%s: %s (%.2f%s)", m_prefix, msg, time_ms, units); + } + +private: + std::chrono::microseconds m_start_t{}; + + //! Log prefix; usually the name of the function this was created in. + const std::string m_prefix{}; + + //! A descriptive message of what is being timed. + const std::string m_title{}; + + //! Forwarded on to LogPrint if specified - has the effect of only + //! outputing the timing log when a particular debug= category is specified. + const BCLog::LogFlags m_log_category{}; + +}; + +} // namespace BCLog + + +#define LOG_TIME_MICROS(end_msg, ...) \ + BCLog::Timer<std::chrono::microseconds> PASTE2(logging_timer, __COUNTER__)(__func__, end_msg, ## __VA_ARGS__) +#define LOG_TIME_MILLIS(end_msg, ...) \ + BCLog::Timer<std::chrono::milliseconds> PASTE2(logging_timer, __COUNTER__)(__func__, end_msg, ## __VA_ARGS__) +#define LOG_TIME_SECONDS(end_msg, ...) \ + BCLog::Timer<std::chrono::seconds> PASTE2(logging_timer, __COUNTER__)(__func__, end_msg, ## __VA_ARGS__) + + +#endif // BITCOIN_LOGGING_TIMER_H diff --git a/src/test/logging_tests.cpp b/src/test/logging_tests.cpp new file mode 100644 index 0000000000..eb1826ae8d --- /dev/null +++ b/src/test/logging_tests.cpp @@ -0,0 +1,36 @@ +// Copyright (c) 2019 The Bitcoin Core developers +// Distributed under the MIT software license, see the accompanying +// file COPYING or http://www.opensource.org/licenses/mit-license.php. + +#include <logging.h> +#include <logging/timer.h> +#include <test/setup_common.h> + +#include <chrono> + +#include <boost/test/unit_test.hpp> + +BOOST_FIXTURE_TEST_SUITE(logging_tests, BasicTestingSetup) + +BOOST_AUTO_TEST_CASE(logging_timer) +{ + + SetMockTime(1); + auto sec_timer = BCLog::Timer<std::chrono::seconds>("tests", "end_msg"); + SetMockTime(2); + BOOST_CHECK_EQUAL(sec_timer.LogMsg("test secs"), "tests: test secs (1.00s)"); + + SetMockTime(1); + auto ms_timer = BCLog::Timer<std::chrono::milliseconds>("tests", "end_msg"); + SetMockTime(2); + BOOST_CHECK_EQUAL(ms_timer.LogMsg("test ms"), "tests: test ms (1000.00ms)"); + + SetMockTime(1); + auto micro_timer = BCLog::Timer<std::chrono::microseconds>("tests", "end_msg"); + SetMockTime(2); + BOOST_CHECK_EQUAL(micro_timer.LogMsg("test micros"), "tests: test micros (1000000.00μs)"); + + SetMockTime(0); +} + +BOOST_AUTO_TEST_SUITE_END() |