[ngcore] Profiler

Author: mhochsteger

libsrc/core/CMakeLists.txt

@@ -1,5 +1,5 @@
 
-add_library(ngcore SHARED archive.cpp logging.cpp paje_trace.cpp utils.cpp)
+add_library(ngcore SHARED archive.cpp logging.cpp paje_trace.cpp utils.cpp profiler.cpp)
 
 target_compile_definitions(ngcore PRIVATE NGCORE_EXPORTS)
 if(NOT WIN32)
@@ -32,7 +32,7 @@ if(USE_PYTHON)
 endif(USE_PYTHON)
 
 install(FILES ngcore.hpp archive.hpp type_traits.hpp version.hpp ngcore_api.hpp logging.hpp
-  exception.hpp symboltable.hpp paje_trace.hpp utils.hpp
+  exception.hpp symboltable.hpp paje_trace.hpp utils.hpp profiler.hpp
   DESTINATION ${NG_INSTALL_DIR_INCLUDE}/core COMPONENT netgen_devel)
 
 if(ENABLE_CPP_CORE_GUIDELINES_CHECK)

libsrc/core/paje_trace.cpp

@@ -5,8 +5,9 @@
 #include <vector>
 #include <x86intrin.h>   // for __rdtsc()  CPU time step counter
 
-#include "ngcore_api.hpp"    // for NGCORE_API
 #include "logging.hpp"       // for logger
+#include "ngcore_api.hpp"    // for NGCORE_API
+#include "utils.hpp"
 
 namespace ngcore
 {
@@ -15,15 +16,11 @@ namespace ngcore
   class PajeTrace
     {
     public:
-      typedef std::chrono::system_clock TClock;
-      // typedef TClock::time_point TTimePoint;
-      typedef size_t TTimePoint;
+      using TClock = std::chrono::system_clock;
 
     protected:
       std::shared_ptr<spdlog::logger> logger = GetLogger("PajeTrace");
     private:
-      friend class TraceDisabler;
-
       NGCORE_API static size_t max_tracefile_size;
       static bool trace_thread_counter;
       static bool trace_threads;
@@ -104,32 +101,32 @@ namespace ngcore
       std::vector<TimerEvent> timer_events;
       std::vector<std::vector<ThreadLink> > links;
 
-      TTimePoint GetTime()
-        {
-          // return TClock::now();
-          return TTimePoint(__rdtsc());
-        }
-
     public:
       NGCORE_API void StopTracing();
 
+      PajeTrace() = delete;
+      PajeTrace(const PajeTrace &) = delete;
+      PajeTrace(PajeTrace &&) = delete;
       PajeTrace(int anthreads, std::string aname = "");
       ~PajeTrace();
 
+      void operator=(const PajeTrace &) = delete;
+      void operator=(PajeTrace &&) = delete;
+
       void StartTimer(int timer_id)
         {
           if(!tracing_enabled) return;
           if(unlikely(timer_events.size() == max_num_events_per_thread))
             StopTracing();
-          timer_events.push_back(TimerEvent{timer_id, GetTime(), true});
+          timer_events.push_back(TimerEvent{timer_id, GetTimeCounter(), true});
         }
 
       void StopTimer(int timer_id)
         {
           if(!tracing_enabled) return;
           if(unlikely(timer_events.size() == max_num_events_per_thread))
             StopTracing();
-          timer_events.push_back(TimerEvent{timer_id, GetTime(), false});
+          timer_events.push_back(TimerEvent{timer_id, GetTimeCounter(), false});
         }
 
       NETGEN_INLINE int StartTask(int thread_id, int id, int id_type = Task::ID_NONE, int additional_value = -1)
@@ -139,15 +136,15 @@ namespace ngcore
 	  if(unlikely(tasks[thread_id].size() == max_num_events_per_thread))
             StopTracing();
           int task_num = tasks[thread_id].size();
-          tasks[thread_id].push_back( Task{thread_id, id, id_type, additional_value, GetTime()} );
+          tasks[thread_id].push_back( Task{thread_id, id, id_type, additional_value, GetTimeCounter()} );
           return task_num;
         }
 
       void StopTask(int thread_id, int task_num)
         {
           if(!trace_threads && !trace_thread_counter) return;
           if(task_num>=0)
-            tasks[thread_id][task_num].stop_time = GetTime();
+            tasks[thread_id][task_num].stop_time = GetTimeCounter();
         }
 
       void SetTask(int thread_id, int task_num, int additional_value) {
@@ -161,55 +158,34 @@ namespace ngcore
           if(!tracing_enabled) return;
           if(jobs.size() == max_num_events_per_thread)
             StopTracing();
-          jobs.push_back( Job{job_id, &type, GetTime()} );
+          jobs.push_back( Job{job_id, &type, GetTimeCounter()} );
         }
 
       void StopJob()
         {
           if(tracing_enabled)
-            jobs.back().stop_time = GetTime();
+            jobs.back().stop_time = GetTimeCounter();
         }
 
       void StartLink(int thread_id, int key)
         {
           if(!tracing_enabled) return;
           if(links[thread_id].size() == max_num_events_per_thread)
             StopTracing();
-          links[thread_id].push_back( ThreadLink{thread_id, key, GetTime(), true} );
+          links[thread_id].push_back( ThreadLink{thread_id, key, GetTimeCounter(), true} );
         }
 
       void StopLink(int thread_id, int key)
         {
           if(!tracing_enabled) return;
           if(links[thread_id].size() == max_num_events_per_thread)
             StopTracing();
-          links[thread_id].push_back( ThreadLink{thread_id, key, GetTime(), false} );
+          links[thread_id].push_back( ThreadLink{thread_id, key, GetTimeCounter(), false} );
         }
 
-      void Write( std::string filename );
-
-    };
+      void Write( const std::string & filename );
 
-  class TraceDisabler
-    {
-      bool trace_thread_counter;
-      bool trace_threads;
-
-    public:
-      TraceDisabler()
-        {
-          trace_thread_counter = PajeTrace::trace_thread_counter;
-          PajeTrace::trace_thread_counter = false;
-          trace_threads = PajeTrace::trace_threads;
-          PajeTrace::trace_threads = false;
-        }
-
-      ~TraceDisabler()
-        {
-          PajeTrace::trace_thread_counter = trace_thread_counter;
-          PajeTrace::trace_threads = trace_threads;
-        }
     };
-}
+} // namespace ngcore
 
 #endif // NETGEN_CORE_PAJE_TRACE_HPP

libsrc/core/paje_trace.hpp

@@ -0,0 +1,106 @@
+#include <mutex>
+
+#include "profiler.hpp"
+
+namespace ngcore
+{
+  std::array<NgProfiler::TimerVal,NgProfiler::SIZE> NgProfiler::timers; // NOLINT
+
+  std::string NgProfiler::filename;
+
+  size_t dummy_thread_times[NgProfiler::SIZE];
+  size_t * NgProfiler::thread_times = dummy_thread_times; // NOLINT
+  size_t dummy_thread_flops[NgProfiler::SIZE];
+  size_t * NgProfiler::thread_flops = dummy_thread_flops; // NOLINT
+
+  std::shared_ptr<spdlog::logger> logger = GetLogger("Profiler"); // NOLINT
+
+  NgProfiler :: NgProfiler()
+  {
+    for (auto & t : timers)
+    {
+        t.tottime = 0.0;
+        t.usedcounter = 0;
+        t.flops = 0.0;
+    }
+  }
+
+  NgProfiler :: ~NgProfiler()
+  {
+    if (filename.length())
+      {
+        logger->debug( "write profile to file {}", filename );
+        FILE *prof = fopen(filename.c_str(),"w"); // NOLINT
+        Print (prof);
+        fclose(prof); // NOLINT
+      }
+
+  }
+
+  void NgProfiler :: Print (FILE * prof)
+  {
+    int i = 0;
+    for (auto & t : timers)
+    {
+      if (t.count != 0 || t.usedcounter != 0)
+        {
+          fprintf(prof,"job %3i calls %8li, time %6.4f sec",i,t.count,t.tottime); // NOLINT
+          if(t.flops != 0.0)
+            fprintf(prof,", MFlops = %6.2f",t.flops / (t.tottime) * 1e-6); // NOLINT
+          if(t.loads != 0.0)
+            fprintf(prof,", MLoads = %6.2f",t.loads / (t.tottime) * 1e-6); // NOLINT
+          if(t.stores != 0.0)
+            fprintf(prof,", MStores = %6.2f",t.stores / (t.tottime) * 1e-6); // NOLINT
+          if(t.usedcounter)
+            fprintf(prof," %s",t.name.c_str()); // NOLINT
+          fprintf(prof,"\n"); // NOLINT
+        }
+      i++;
+    }
+  }
+
+
+  int NgProfiler :: CreateTimer (const std::string & name)
+  {
+    static std::mutex createtimer_mutex;
+    int nr = -1;
+    {
+      std::lock_guard<std::mutex> guard(createtimer_mutex);
+      for (int i = SIZE-1; i > 0; i--)
+      {
+        auto & t = timers[i];
+        if (!t.usedcounter)
+          {
+            t.usedcounter = 1;
+            t.name = name;
+            nr = i;
+            break;
+          }
+      }
+    }
+    if (nr > -1) return nr;
+    static bool first_overflow = true;
+    if (first_overflow)
+      {
+        first_overflow = false;
+        NgProfiler::logger->warn("no more timer available, reusing last one");
+      }
+    return 0;
+  }
+
+  void NgProfiler :: Reset ()
+  {
+      for(auto & t : timers)
+      {
+          t.tottime = 0.0;
+          t.count = 0;
+          t.flops = 0.0;
+          t.loads = 0;
+          t.stores = 0;
+      }
+  }
+
+  NgProfiler prof; // NOLINT
+
+
+} // namespace ngcore