perf_timer: add faster x86_64 timers, and pause/resume

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<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_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()
 
 }