From 411da337d2026b8c4603484c4b8300ea933b10c0 Mon Sep 17 00:00:00 2001 From: moneromooo-monero Date: Wed, 3 Jan 2018 21:36:51 +0000 Subject: [PATCH 1/2] perf_timer: use std::unique_ptr instead of new/delete --- src/common/perf_timer.h | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/src/common/perf_timer.h b/src/common/perf_timer.h index a1d71609c..2b318bff2 100644 --- a/src/common/perf_timer.h +++ b/src/common/perf_timer.h @@ -30,6 +30,7 @@ #include #include +#include #include "misc_log_ex.h" #undef MONERO_DEFAULT_LOG_CATEGORY @@ -62,8 +63,8 @@ void set_performance_timer_log_level(el::Level level); #define PERF_TIMER_UNIT_L(name, unit, l) tools::PerformanceTimer pt_##name(#name, unit, l) #define PERF_TIMER(name) PERF_TIMER_UNIT(name, 1000) #define PERF_TIMER_L(name, l) PERF_TIMER_UNIT_L(name, 1000, l) -#define PERF_TIMER_START_UNIT(name, unit) tools::PerformanceTimer *pt_##name = new tools::PerformanceTimer(#name, unit, el::Level::Info) +#define PERF_TIMER_START_UNIT(name, unit) std::unique_ptr pt_##name(new tools::PerformanceTimer(#name, unit, el::Level::Info)) #define PERF_TIMER_START(name) PERF_TIMER_START_UNIT(name, 1000) -#define PERF_TIMER_STOP(name) do { delete pt_##name; pt_##name = NULL; } while(0) +#define PERF_TIMER_STOP(name) do { pt_##name.reset(NULL); } while(0) } From 6cf56682bc156f66cdbb290c9494c52501e2f5df Mon Sep 17 00:00:00 2001 From: moneromooo-monero Date: Mon, 8 Jan 2018 10:53:42 +0000 Subject: [PATCH 2/2] perf_timer: add faster x86_64 timers, and pause/resume --- src/common/perf_timer.cpp | 79 +++++++++++++++++++++++++++++++++++---- src/common/perf_timer.h | 5 +++ 2 files changed, 77 insertions(+), 7 deletions(-) diff --git a/src/common/perf_timer.cpp b/src/common/perf_timer.cpp index 4947058d3..62840a0eb 100644 --- a/src/common/perf_timer.cpp +++ b/src/common/perf_timer.cpp @@ -33,6 +33,52 @@ #undef MONERO_DEFAULT_LOG_CATEGORY #define MONERO_DEFAULT_LOG_CATEGORY "perf" +namespace +{ + uint64_t get_tick_count() + { +#if defined(__x86_64__) + uint32_t hi, lo; + __asm__ volatile("rdtsc" : "=a"(lo), "=d"(hi)); + return (((uint64_t)hi) << 32) | (uint64_t)lo; +#else + return epee::misc_utils::get_ns_count(); +#endif + } + +#ifdef __x86_64__ + uint64_t get_ticks_per_ns() + { + uint64_t t0 = epee::misc_utils::get_ns_count(); + uint64_t r0 = get_tick_count(); + + while (1) + { + uint64_t t = epee::misc_utils::get_ns_count(); + if (t - t0 > 1*1000000000) break; // work one second + } + + uint64_t t1 = epee::misc_utils::get_ns_count(); + uint64_t r1 = get_tick_count(); + uint64_t tpns256 = 256 * (r1 - r0) / (t1 - t0); + return tpns256 ? tpns256 : 1; + } +#endif + +#ifdef __x86_64__ + uint64_t ticks_per_ns = get_ticks_per_ns(); +#endif + + uint64_t ticks_to_ns(uint64_t ticks) + { +#if defined(__x86_64__) + return 256 * ticks / ticks_per_ns; +#else + return ticks; +#endif + } +} + namespace tools { @@ -51,9 +97,9 @@ void set_performance_timer_log_level(el::Level level) performance_timer_log_level = level; } -PerformanceTimer::PerformanceTimer(const std::string &s, uint64_t unit, el::Level l): name(s), unit(unit), level(l), started(false) +PerformanceTimer::PerformanceTimer(const std::string &s, uint64_t unit, el::Level l): name(s), unit(unit), level(l), started(false), paused(false) { - ticks = epee::misc_utils::get_ns_count(); + ticks = get_tick_count(); if (!performance_timers) { MLOG(level, "PERF ----------"); @@ -62,9 +108,10 @@ PerformanceTimer::PerformanceTimer(const std::string &s, uint64_t unit, el::Leve else { PerformanceTimer *pt = performance_timers->back(); - if (!pt->started) + if (!pt->started && !pt->paused) { - MLOG(pt->level, "PERF " << std::string((performance_timers->size()-1) * 2, ' ') << " " << pt->name); + size_t size = 0; for (const auto *tmp: *performance_timers) if (!tmp->paused) ++size; + MLOG(pt->level, "PERF " << std::string((size-1) * 2, ' ') << " " << pt->name); pt->started = true; } } @@ -74,10 +121,12 @@ PerformanceTimer::PerformanceTimer(const std::string &s, uint64_t unit, el::Leve PerformanceTimer::~PerformanceTimer() { performance_timers->pop_back(); - ticks = epee::misc_utils::get_ns_count() - ticks; + if (!paused) + ticks = get_tick_count() - ticks; char s[12]; - snprintf(s, sizeof(s), "%8llu ", (unsigned long long)ticks / (1000000000 / unit)); - MLOG(level, "PERF " << s << std::string(performance_timers->size() * 2, ' ') << " " << name); + snprintf(s, sizeof(s), "%8llu ", (unsigned long long)(ticks_to_ns(ticks) / (1000000000 / unit))); + size_t size = 0; for (const auto *tmp: *performance_timers) if (!tmp->paused || tmp==this) ++size; + MLOG(level, "PERF " << s << std::string(size * 2, ' ') << " " << name); if (performance_timers->empty()) { delete performance_timers; @@ -85,4 +134,20 @@ PerformanceTimer::~PerformanceTimer() } } +void PerformanceTimer::pause() +{ + if (paused) + return; + ticks = get_tick_count() - ticks; + paused = true; +} + +void PerformanceTimer::resume() +{ + if (!paused) + return; + ticks = get_tick_count() - ticks; + paused = false; +} + } diff --git a/src/common/perf_timer.h b/src/common/perf_timer.h index 2b318bff2..536cfddd0 100644 --- a/src/common/perf_timer.h +++ b/src/common/perf_timer.h @@ -48,6 +48,8 @@ class PerformanceTimer public: PerformanceTimer(const std::string &s, uint64_t unit, el::Level l = el::Level::Debug); ~PerformanceTimer(); + void pause(); + void resume(); private: std::string name; @@ -55,6 +57,7 @@ private: el::Level level; uint64_t ticks; bool started; + bool paused; }; void set_performance_timer_log_level(el::Level level); @@ -66,5 +69,7 @@ void set_performance_timer_log_level(el::Level level); #define PERF_TIMER_START_UNIT(name, unit) std::unique_ptr pt_##name(new tools::PerformanceTimer(#name, unit, el::Level::Info)) #define PERF_TIMER_START(name) PERF_TIMER_START_UNIT(name, 1000) #define PERF_TIMER_STOP(name) do { pt_##name.reset(NULL); } while(0) +#define PERF_TIMER_PAUSE(name) pt_##name->pause() +#define PERF_TIMER_RESUME(name) pt_##name->resume() }