perf_timer: add faster x86_64 timers, and pause/resume

This commit is contained in:
moneromooo-monero 2018-01-08 10:53:42 +00:00
parent 411da337d2
commit 6cf56682bc
No known key found for this signature in database
GPG Key ID: 686F07454D6CEFC3
2 changed files with 77 additions and 7 deletions

View File

@ -33,6 +33,52 @@
#undef MONERO_DEFAULT_LOG_CATEGORY #undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "perf" #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 namespace tools
{ {
@ -51,9 +97,9 @@ void set_performance_timer_log_level(el::Level level)
performance_timer_log_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) if (!performance_timers)
{ {
MLOG(level, "PERF ----------"); MLOG(level, "PERF ----------");
@ -62,9 +108,10 @@ PerformanceTimer::PerformanceTimer(const std::string &s, uint64_t unit, el::Leve
else else
{ {
PerformanceTimer *pt = performance_timers->back(); 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; pt->started = true;
} }
} }
@ -74,10 +121,12 @@ PerformanceTimer::PerformanceTimer(const std::string &s, uint64_t unit, el::Leve
PerformanceTimer::~PerformanceTimer() PerformanceTimer::~PerformanceTimer()
{ {
performance_timers->pop_back(); performance_timers->pop_back();
ticks = epee::misc_utils::get_ns_count() - ticks; if (!paused)
ticks = get_tick_count() - ticks;
char s[12]; char s[12];
snprintf(s, sizeof(s), "%8llu ", (unsigned long long)ticks / (1000000000 / unit)); snprintf(s, sizeof(s), "%8llu ", (unsigned long long)(ticks_to_ns(ticks) / (1000000000 / unit)));
MLOG(level, "PERF " << s << std::string(performance_timers->size() * 2, ' ') << " " << name); 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()) if (performance_timers->empty())
{ {
delete performance_timers; 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;
}
} }

View File

@ -48,6 +48,8 @@ class PerformanceTimer
public: public:
PerformanceTimer(const std::string &s, uint64_t unit, el::Level l = el::Level::Debug); PerformanceTimer(const std::string &s, uint64_t unit, el::Level l = el::Level::Debug);
~PerformanceTimer(); ~PerformanceTimer();
void pause();
void resume();
private: private:
std::string name; std::string name;
@ -55,6 +57,7 @@ private:
el::Level level; el::Level level;
uint64_t ticks; uint64_t ticks;
bool started; bool started;
bool paused;
}; };
void set_performance_timer_log_level(el::Level level); 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<tools::PerformanceTimer> pt_##name(new tools::PerformanceTimer(#name, unit, el::Level::Info)) #define PERF_TIMER_START_UNIT(name, unit) std::unique_ptr<tools::PerformanceTimer> pt_##name(new tools::PerformanceTimer(#name, unit, el::Level::Info))
#define PERF_TIMER_START(name) PERF_TIMER_START_UNIT(name, 1000) #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_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()
} }