[Bf-blender-cvs] [0bbf940965e] functions: better timing statistics

[Jacques Lucke]

Commit: 0bbf940965eae0ceced575946231228bbab1c229
Author: Jacques Lucke
Date:   Sun Jun 30 09:49:10 2019 +0200
Branches: functions
https://developer.blender.org/rB0bbf940965eae0ceced575946231228bbab1c229

better timing statistics

===================================================================

M	source/blender/blenlib/BLI_timeit.hpp
M	source/blender/simulations/bparticles/simulate.cpp

===================================================================

diff --git a/source/blender/blenlib/BLI_timeit.hpp b/source/blender/blenlib/BLI_timeit.hpp
index 7628c83f4a3..9cbaea8369a 100644
--- a/source/blender/blenlib/BLI_timeit.hpp
+++ b/source/blender/blenlib/BLI_timeit.hpp
@@ -31,9 +31,8 @@ class ScopedTimer {
   TimePoint m_start;
 
  public:
-  ScopedTimer(const char *name = "")
+  ScopedTimer(const char *name = "") : m_name(name)
   {
-    m_name = name;
     m_start = Clock::now();
   }
 
@@ -47,8 +46,59 @@ class ScopedTimer {
   }
 };
 
+class ScopedTimerStatistics {
+ private:
+  TimePoint m_start;
+  const char *m_name;
+  Nanoseconds &m_shortest_duration;
+  Nanoseconds &m_timings_sum;
+  uint64_t &m_timings_done;
+
+ public:
+  ScopedTimerStatistics(const char *name,
+                        Nanoseconds &shortest_duration,
+                        Nanoseconds &timings_sum,
+                        uint64_t &timings_done)
+      : m_name(name),
+        m_shortest_duration(shortest_duration),
+        m_timings_sum(timings_sum),
+        m_timings_done(timings_done)
+  {
+    m_start = Clock::now();
+  }
+
+  ~ScopedTimerStatistics()
+  {
+    TimePoint end = Clock::now();
+    Nanoseconds duration = end - m_start;
+    m_timings_sum += duration;
+    m_timings_done++;
+
+    if (duration < m_shortest_duration) {
+      m_shortest_duration = duration;
+    }
+
+    Nanoseconds average_duration = m_timings_sum / m_timings_done;
+
+    std::cout << "Timings stats for '" << m_name << "':\n";
+    std::cout << "  Calls: " << m_timings_done << "\n";
+    std::cout << "  Average: ";
+    print_duration(average_duration);
+    std::cout << "\n";
+    std::cout << "  Shortest: ";
+    print_duration(m_shortest_duration);
+    std::cout << "\n";
+  }
+};
+
 }  // namespace Timers
 
 };  // namespace BLI
 
 #define SCOPED_TIMER(name) BLI::Timers::ScopedTimer t(name);
+
+#define SCOPED_TIMER_STATS(name) \
+  static uint64_t timings_done = 0; \
+  static BLI::Timers::Nanoseconds shortest_duration = std::chrono::seconds(100); \
+  static BLI::Timers::Nanoseconds timings_sum(0); \
+  BLI::Timers::ScopedTimerStatistics t(name, shortest_duration, timings_sum, timings_done);
diff --git a/source/blender/simulations/bparticles/simulate.cpp b/source/blender/simulations/bparticles/simulate.cpp
index e25de26cef3..f9c1281e792 100644
--- a/source/blender/simulations/bparticles/simulate.cpp
+++ b/source/blender/simulations/bparticles/simulate.cpp
@@ -426,7 +426,7 @@ BLI_NOINLINE static void simulate_block_time_span_cb(void *__restrict userdata,
                                                      const int index,
                                                      const ParallelRangeTLS *__restrict tls)
 {
-  SCOPED_TIMER(__func__);
+  SCOPED_TIMER_STATS(__func__);
 
   SimulateTimeSpanData *data = (SimulateTimeSpanData *)userdata;