[ngcore] Profiler

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

@@ -1,9 +1,9 @@
 #include <algorithm>
 #include <atomic>
+#include <iostream>
 #include <map>
 #include <set>
 #include <thread>
-#include <iostream>
 
 #include "archive.hpp"           // for Demangle
 #include "paje_trace.hpp"
@@ -23,13 +23,13 @@ namespace ngcore
 
   PajeTrace :: PajeTrace(int anthreads, std::string aname)
   {
-    start_time = GetTime();
+    start_time = GetTimeCounter();
 
     nthreads = anthreads;
-    tracefile_name = aname;
+    tracefile_name = std::move(aname);
 
     int bytes_per_event=33;
-    max_num_events_per_thread = std::min( (size_t)std::numeric_limits<int>::max, max_tracefile_size/bytes_per_event/(2*nthreads+1)*10/7);
+    max_num_events_per_thread = std::min( static_cast<size_t>(std::numeric_limits<int>::max()), max_tracefile_size/bytes_per_event/(2*nthreads+1)*10/7);
     if(max_num_events_per_thread>0)
     {
       logger->info( "Tracefile size = {}MB", max_tracefile_size/1024/1024);
@@ -53,7 +53,7 @@ namespace ngcore
 
   PajeTrace :: ~PajeTrace()
   {
-    if(tracefile_name.size()>0)
+    if(!tracefile_name.empty())
       Write(tracefile_name);
   }
 
@@ -67,11 +67,9 @@ namespace ngcore
       tracing_enabled = false;
     }
 
-  using std::string;
   class PajeFile
     {
     public:
-      typedef PajeTrace::TTimePoint TTimePoint;
       static void Hue2RGB ( double x, double &r, double &g, double &b )
         {
           double d = 1.0/6.0;
@@ -139,36 +137,35 @@ namespace ngcore
           bool value_is_alias = true;
 
           bool operator < (const PajeEvent & other) const {
-              // Same times can occur for very small tasks -> take "starting" events first (eg. PajePushState before PajePopState)
+              // Same start and stop times can occur for very small tasks -> take "starting" events first (eg. PajePushState before PajePopState)
               if(time == other.time)
                 return event_type < other.event_type;
-              else
+              return (time < other.time);
-                return (time < other.time);
           }
 
-          int write(char *buf)
+          int write(FILE *stream)
             {
               const int &key = id;
               const int &end_container = start_container;
               switch(event_type)
                 {
                 case PajeSetVariable:
-                  return sprintf( buf, "%d\t%.15g\ta%d\ta%d\t%.15g\n", PajeSetVariable, time, type, container, var_value );
+                  return fprintf( stream, "%d\t%.15g\ta%d\ta%d\t%.15g\n", PajeSetVariable, time, type, container, var_value ); // NOLINT
                 case PajeAddVariable:
-                  return sprintf( buf, "%d\t%.15g\ta%d\ta%d\t%.15g\n", PajeAddVariable, time, type, container, var_value );
+                  return fprintf( stream, "%d\t%.15g\ta%d\ta%d\t%.15g\n", PajeAddVariable, time, type, container, var_value ); // NOLINT
                 case PajeSubVariable:
-                  return sprintf( buf, "%d\t%.15g\ta%d\ta%d\t%.15g\n", PajeSubVariable, time, type, container, var_value );
+                  return fprintf( stream, "%d\t%.15g\ta%d\ta%d\t%.15g\n", PajeSubVariable, time, type, container, var_value ); // NOLINT
                 case PajePushState:
                   if(value_is_alias)
-                    return sprintf( buf, "%d\t%.15g\ta%d\ta%d\ta%d\t%d\n", PajePushState, time, type, container, value, id);
+                    return fprintf( stream, "%d\t%.15g\ta%d\ta%d\ta%d\t%d\n", PajePushState, time, type, container, value, id); // NOLINT
                   else
-                    return sprintf( buf, "%d\t%.15g\ta%d\ta%d\t%d\t%d\n", PajePushState, time, type, container, value, id);
+                    return fprintf( stream, "%d\t%.15g\ta%d\ta%d\t%d\t%d\n", PajePushState, time, type, container, value, id); // NOLINT
                 case PajePopState:
-                  return sprintf( buf, "%d\t%.15g\ta%d\ta%d\n", PajePopState, time, type, container );
+                  return fprintf( stream, "%d\t%.15g\ta%d\ta%d\n", PajePopState, time, type, container ); // NOLINT
                 case PajeStartLink:
-                  return sprintf( buf, "%d\t%.15g\ta%d\ta%d\t%d\ta%d\t%d\n", PajeStartLink, time, type, container, value, start_container, key );
+                  return fprintf( stream, "%d\t%.15g\ta%d\ta%d\t%d\ta%d\t%d\n", PajeStartLink, time, type, container, value, start_container, key ); // NOLINT
                 case PajeEndLink:
-                  return sprintf( buf, "%d\t%.15g\ta%d\ta%d\t%d\ta%d\t%d\n", PajeEndLink, time, type, container, value, end_container, key );
+                  return fprintf( stream, "%d\t%.15g\ta%d\ta%d\t%d\ta%d\t%d\n", PajeEndLink, time, type, container, value, end_container, key ); // NOLINT
                 }
               return 0;
             }
@@ -177,34 +174,46 @@ namespace ngcore
       std::vector<PajeEvent> events;
 
     public:
-      PajeFile( string filename, TTimePoint astart_time )
+      PajeFile() = delete;
+      PajeFile(const PajeFile &) = delete;
+      PajeFile(PajeFile &&) = delete;
+      void operator=(const PajeFile &) = delete;
+      void operator=(PajeFile &&) = delete;
+
+      PajeFile( const std::string & filename, TTimePoint astart_time )
         {
           start_time = astart_time;
-          ctrace_stream = fopen (filename.c_str(),"w");
+          ctrace_stream = fopen (filename.c_str(),"w"); // NOLINT
-          fprintf(ctrace_stream, "%s", header );
+          fprintf(ctrace_stream, "%s", header ); // NOLINT
           alias_counter = 0;
         }
-      int DefineContainerType ( int parent_type, string name )
+
+      ~PajeFile()
+        {
+          fclose (ctrace_stream); // NOLINT
+        }
+
+      int DefineContainerType ( int parent_type, const std::string & name )
         {
           int alias = ++alias_counter;
           if(parent_type!=0)
-            fprintf( ctrace_stream, "%d\ta%d\ta%d\t\"%s\"\n", PajeDefineContainerType, alias, parent_type, name.c_str() );
+            fprintf( ctrace_stream, "%d\ta%d\ta%d\t\"%s\"\n", PajeDefineContainerType, alias, parent_type, name.c_str() ); // NOLINT
           else
-            fprintf( ctrace_stream, "%d\ta%d\t%d\t\"%s\"\n", PajeDefineContainerType, alias, parent_type, name.c_str() );
+            fprintf( ctrace_stream, "%d\ta%d\t%d\t\"%s\"\n", PajeDefineContainerType, alias, parent_type, name.c_str() ); // NOLINT
           return alias;
         }
 
-      int DefineVariableType ( int container_type, string name )
+      int DefineVariableType ( int container_type, const std::string & name )
         {
           int alias = ++alias_counter;
-          fprintf( ctrace_stream, "%d\ta%d\ta%d\t\"%s\"\t\"1.0 1.0 1.0\"\n", PajeDefineVariableType, alias, container_type, name.c_str() );
+          fprintf( ctrace_stream, "%d\ta%d\ta%d\t\"%s\"\t\"1.0 1.0 1.0\"\n", PajeDefineVariableType, alias, container_type, name.c_str() ); // NOLINT
           return alias;
         }
 
-      int DefineStateType ( int type, string name )
+      int DefineStateType ( int type, const std::string & name )
         {
           int alias = ++alias_counter;
-          fprintf( ctrace_stream, "%d\ta%d\ta%d\t\"%s\"\n", PajeDefineStateType, alias, type, name.c_str() );
+          fprintf( ctrace_stream, "%d\ta%d\ta%d\t\"%s\"\n", PajeDefineStateType, alias, type, name.c_str() ); // NOLINT
           return alias;
         }
 
@@ -213,38 +222,38 @@ namespace ngcore
       //           Write("event not implemented");
       //         }
 
-      int DefineLinkType (int parent_container_type, int start_container_type, int stop_container_type, string name)
+      int DefineLinkType (int parent_container_type, int start_container_type, int stop_container_type, const std::string & name)
         {
           int alias = ++alias_counter;
-          fprintf( ctrace_stream, "%d\ta%d\ta%d\ta%d\ta%d\t\"%s\"\n", PajeDefineLinkType, alias, parent_container_type, start_container_type, stop_container_type, name.c_str() );
+          fprintf( ctrace_stream, "%d\ta%d\ta%d\ta%d\ta%d\t\"%s\"\n", PajeDefineLinkType, alias, parent_container_type, start_container_type, stop_container_type, name.c_str() ); // NOLINT
           return alias;
         }
 
-      int DefineEntityValue (int type, string name, double hue = -1)
+      int DefineEntityValue (int type, const std::string & name, double hue = -1)
         {
           if(hue==-1)
             {
-              std::hash<string> shash;
+              std::hash<std::string> shash;
               size_t h = shash(name);
-              h ^= h>>32;
+              h ^= h>>32U;
-              h = (uint32_t)h;
+              h = static_cast<uint32_t>(h);
               hue = h*1.0/std::numeric_limits<uint32_t>::max();
             }
 
           int alias = ++alias_counter;
           double r,g,b;
           Hue2RGB( hue, r, g, b );
-          fprintf( ctrace_stream, "%d\ta%d\ta%d\t\"%s\"\t\"%.15g %.15g %.15g\"\n", PajeDefineEntityValue, alias, type, name.c_str(), r,g,b );
+          fprintf( ctrace_stream, "%d\ta%d\ta%d\t\"%s\"\t\"%.15g %.15g %.15g\"\n", PajeDefineEntityValue, alias, type, name.c_str(), r,g,b ); // NOLINT
           return alias;
         }
 
-      int CreateContainer ( int type, int parent, string name )
+      int CreateContainer ( int type, int parent, const std::string & name )
         {
           int alias = ++alias_counter;
           if(parent!=0)
-            fprintf( ctrace_stream, "%d\t0\ta%d\ta%d\ta%d\t\"%s\"\n", PajeCreateContainer, alias, type, parent, name.c_str() );
+            fprintf( ctrace_stream, "%d\t0\ta%d\ta%d\ta%d\t\"%s\"\n", PajeCreateContainer, alias, type, parent, name.c_str() ); // NOLINT
           else
-            fprintf( ctrace_stream, "%d\t0\ta%d\ta%d\t%d\t\"%s\"\n", PajeCreateContainer, alias, type, parent, name.c_str() );
+            fprintf( ctrace_stream, "%d\t0\ta%d\ta%d\t%d\t\"%s\"\n", PajeCreateContainer, alias, type, parent, name.c_str() ); // NOLINT
           return alias;
         }
       void DestroyContainer ()
@@ -252,17 +261,17 @@ namespace ngcore
 
       void SetVariable (TTimePoint time, int type, int container, double value )
         {
-          events.push_back( PajeEvent( PajeSetVariable, ConvertTime(time), type, container, value ) );
+          events.emplace_back( PajeEvent( PajeSetVariable, ConvertTime(time), type, container, value ) );
         }
 
       void AddVariable (TTimePoint time, int type, int container, double value )
         {
-          events.push_back( PajeEvent( PajeAddVariable, ConvertTime(time), type, container, value ) );
+          events.emplace_back( PajeEvent( PajeAddVariable, ConvertTime(time), type, container, value ) );
         }
 
       void SubVariable (TTimePoint time, int type, int container, double value )
         {
-          events.push_back( PajeEvent( PajeSubVariable, ConvertTime(time), type, container, value ) );
+          events.emplace_back( PajeEvent( PajeSubVariable, ConvertTime(time), type, container, value ) );
         }
 
       void SetState ()
@@ -270,12 +279,12 @@ namespace ngcore
 
       void PushState ( TTimePoint time, int type, int container, int value, int id = 0, bool value_is_alias = true )
         {
-          events.push_back( PajeEvent( PajePushState, ConvertTime(time), type, container, value, id) );
+          events.emplace_back( PajeEvent( PajePushState, ConvertTime(time), type, container, value, id, value_is_alias) );
         }
 
       void PopState ( TTimePoint time, int type, int container )
         {
-          events.push_back( PajeEvent( PajePopState, ConvertTime(time), type, container ) );
+          events.emplace_back( PajeEvent( PajePopState, ConvertTime(time), type, container ) );
         }
 
       void ResetState ()
@@ -283,12 +292,12 @@ namespace ngcore
 
       void StartLink ( TTimePoint time, int type, int container, int value, int start_container, int key )
         {
-          events.push_back( PajeEvent( PajeStartLink, ConvertTime(time), type, container, value, start_container, key ) );
+          events.emplace_back( PajeEvent( PajeStartLink, ConvertTime(time), type, container, value, start_container, key ) );
         }
 
       void EndLink ( TTimePoint time, int type, int container, int value, int end_container, int key )
         {
-          events.push_back( PajeEvent(  PajeEndLink, ConvertTime(time), type, container, value, end_container, key ) );
+          events.emplace_back( PajeEvent(  PajeEndLink, ConvertTime(time), type, container, value, end_container, key ) );
         }
 
       void NewEvent ()
@@ -299,12 +308,11 @@ namespace ngcore
           logger->info("Sorting traces...");
           std::sort (events.begin(), events.end());
 
-          char buf[2*MAX_TRACE_LINE_SIZE];
           logger->info("Writing traces... ");
-          for (int i = 0; i < events.size(); i++)
+          for (auto & event : events)
           {
-              events[i].write( buf );
+              event.write( ctrace_stream );
-              fprintf( ctrace_stream, "%s", buf );
+//               fprintf( ctrace_stream, "%s", buf ); // NOLINT
           }
           logger->info("Done");
         }
@@ -336,7 +344,7 @@ namespace ngcore
 
   NGCORE_API PajeTrace *trace;
 
-  void PajeTrace::Write( string filename )
+  void PajeTrace::Write( const std::string & filename )
     {
       int n_events = jobs.size() + timer_events.size();
       for(auto & vtasks : tasks)
@@ -352,7 +360,7 @@ namespace ngcore
 
       if(!tracing_enabled)
         {
-            logger->warning("Tracing stopped during computation due to tracefile size limit of {} megabytes.", max_tracefile_size/1024/1024);
+            logger->warn("Tracing stopped during computation due to tracefile size limit of {} megabytes.", max_tracefile_size/1024/1024);
         }
 
       PajeFile paje(filename, start_time);
@@ -374,18 +382,19 @@ namespace ngcore
       paje.SetVariable( start_time, variable_type_active_threads, container_jobs, 0.0 );
 
       const int num_nodes = 1; //task_manager ? task_manager->GetNumNodes() : 1;
-      std::vector<int> container_nodes;
 
+      std::vector<int> container_nodes;
+      container_nodes.reserve(num_nodes);
       for(int i=0; i<num_nodes; i++)
-          container_nodes.push_back( paje.CreateContainer( container_type_node, container_task_manager, "Node " /* TODO: + ToString(i) */));
+          container_nodes.emplace_back( paje.CreateContainer( container_type_node, container_task_manager, "Node " + ToString(i)) );
 
       std::vector <int> thread_aliases;
+      thread_aliases.reserve(nthreads);
       if(trace_threads)
         for (int i=0; i<nthreads; i++)
           {
-            char name[20];
+            auto name = "Timer level " + ToString(i);
-            sprintf(name, "Thread %d", i);
+            thread_aliases.emplace_back( paje.CreateContainer( container_type_thread, container_nodes[i*num_nodes/nthreads], name ) );
-            thread_aliases.push_back( paje.CreateContainer( container_type_thread, container_nodes[i*num_nodes/nthreads], name ) );
           }
 
       std::map<const std::type_info *, int> job_map;
@@ -394,7 +403,7 @@ namespace ngcore
       for(Job & j : jobs)
         if(job_map.find(j.type) == job_map.end())
           {
-            string name = Demangle(j.type->name());
+            std::string name = Demangle(j.type->name());
             job_map[j.type] = paje.DefineEntityValue( state_type_job, name, -1 );
             job_task_map[j.type] = paje.DefineEntityValue( state_type_task, name, -1 );
           }
@@ -437,8 +446,7 @@ namespace ngcore
       timer_container_aliases.resize(maxdepth);
       for(int i=0; i<maxdepth; i++)
         {
-          char name[30];
+          auto name = "Timer level " + ToString(i);
-          sprintf(name, "Timer level %d", i);
           timer_container_aliases[i] =  paje.CreateContainer( container_type_timer, container_task_manager, name );
         }
 
@@ -497,10 +505,10 @@ namespace ngcore
       while(nlinks_merged < nlinks)
         {
           int minpos = -1;
-          TTimePoint mintime;
+          TTimePoint mintime = -1;
           for (int t = 0; t<nthreads; t++)
             {
-              if(pos[t] < links[t].size() && (links[t][pos[t]].time < mintime || minpos==-1))
+              if(pos[t] < links[t].size() && (minpos==-1 || links[t][pos[t]].time < mintime))
                 {
                   minpos = t;
                   mintime = links[t][pos[t]].time;
@@ -544,7 +552,7 @@ namespace ngcore
         }
       paje.WriteEvents();
     }
-}
+} // namespace ngcore
 
 const char *header =
         "%EventDef PajeDefineContainerType 0 \n"

libsrc/core/paje_trace.hpp

@@ -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;
+      using TClock = std::chrono::system_clock;
-      // typedef TClock::time_point TTimePoint;
-      typedef size_t TTimePoint;
 
     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,24 +101,24 @@ 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)
@@ -129,7 +126,7 @@ namespace ngcore
           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,7 +136,7 @@ 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;
         }
 
@@ -147,7 +144,7 @@ namespace ngcore
         {
           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,13 +158,13 @@ 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)
@@ -175,7 +172,7 @@ namespace ngcore
           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)
@@ -183,33 +180,12 @@ namespace ngcore
           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 );
 
     };
-
+} // namespace ngcore
-  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;
-        }
-    };
-}
 
 #endif // NETGEN_CORE_PAJE_TRACE_HPP

libsrc/core/profiler.cpp

@@ -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

libsrc/core/profiler.hpp

@@ -0,0 +1,286 @@
+#ifndef NETGEN_CORE_PROFILER_HPP
+#define NETGEN_CORE_PROFILER_HPP
+
+#include <chrono>
+#include <string>
+
+#include "logging.hpp"
+#include "paje_trace.hpp"
+#include "utils.hpp"
+
+namespace ngcore
+{
+  class NgProfiler
+  {
+  public:
+    /// maximal number of timers
+    enum { SIZE = 8*1024 };
+
+    struct TimerVal
+    {
+        TimerVal() = default;
+
+        double tottime = 0.0;
+        double starttime = 0.0;
+        double flops = 0.0;
+        double loads = 0.0;
+        double stores = 0.0;
+        long count = 0;
+        std::string name = "";
+        int usedcounter = 0;
+    };
+
+    NGCORE_API static std::array<TimerVal,SIZE> timers;
+
+    NGCORE_API static TTimePoint * thread_times;
+    NGCORE_API static TTimePoint * thread_flops;
+    NGCORE_API static std::shared_ptr<spdlog::logger> logger;
+  private:
+
+    static std::string filename;
+  public:
+    NgProfiler();
+    ~NgProfiler();
+
+    NgProfiler(const NgProfiler &) = delete;
+    NgProfiler(NgProfiler &&) = delete;
+    void operator=(const NgProfiler &) = delete;
+    void operator=(NgProfiler &&) = delete;
+
+    static void SetFileName (const std::string & afilename) { filename = afilename; }
+
+    /// create new timer, use integer index
+    NGCORE_API static int CreateTimer (const std::string & name);
+
+    NGCORE_API static void Reset ();
+
+
+    /// start timer of index nr
+    static void StartTimer (int nr)
+    {
+      timers[nr].starttime = WallTime(); timers[nr].count++;
+    }
+
+    /// stop timer of index nr
+    static void StopTimer (int nr)
+    {
+      timers[nr].tottime += WallTime()-timers[nr].starttime;
+    }
+
+    static void StartThreadTimer (size_t nr, size_t tid)
+    {
+      thread_times[tid*SIZE+nr] -= GetTimeCounter();
+    }
+
+    static void StopThreadTimer (size_t nr, size_t tid)
+    {
+      thread_times[tid*SIZE+nr] += GetTimeCounter();
+    }
+
+    static void AddThreadFlops (size_t nr, size_t tid, size_t flops)
+    {
+      thread_flops[tid*SIZE+nr] += flops;
+    }
+
+    /// if you know number of flops, provide them to obtain the MFlop - rate
+    static void AddFlops (int nr, double aflops) { timers[nr].flops += aflops; }
+    static void AddLoads (int nr, double aloads) { timers[nr].loads += aloads; }
+    static void AddStores (int nr, double astores) { timers[nr].stores += astores; }
+
+    static int GetNr (const std::string & name)
+    {
+      for (int i = SIZE-1; i >= 0; i--)
+        if (timers[i].name == name)
+          return i;
+      return -1;
+    }
+
+    static double GetTime (int nr)
+    {
+      return timers[nr].tottime;
+    }
+
+    static double GetTime (const std::string & name)
+    {
+      for (int i = SIZE-1; i >= 0; i--)
+        if (timers[i].name == name)
+          return GetTime (i);
+      return 0;
+    }
+
+    static long int GetCounts (int nr)
+    {
+      return timers[nr].count;
+    }
+
+    static double GetFlops (int nr)
+    {
+      return timers[nr].flops;
+    }
+
+    /// change name
+    static void SetName (int nr, const std::string & name) { timers[nr].name = name; }
+    static std::string GetName (int nr) { return timers[nr].name; }
+    /// print profile
+    NGCORE_API static void Print (FILE * ost);
+  };
+
+
+
+  class Timer
+  {
+    int timernr;
+    int priority;
+  public:
+    Timer (const std::string & name, int apriority = 1)
+      : priority(apriority)
+    {
+      timernr = NgProfiler::CreateTimer (name);
+    }
+    void SetName (const std::string & name)
+    {
+      NgProfiler::SetName (timernr, name);
+    }
+    void Start ()
+    {
+      if (priority <= 2)
+	NgProfiler::StartTimer (timernr);
+      if (priority <= 1)
+        if(trace) trace->StartTimer(timernr);
+    }
+    void Stop ()
+    {
+      if (priority <= 2)
+	NgProfiler::StopTimer (timernr);
+      if (priority <= 1)
+        if(trace) trace->StopTimer(timernr);
+    }
+    void AddFlops (double aflops)
+    {
+      if (priority <= 2)
+	NgProfiler::AddFlops (timernr, aflops);
+    }
+
+    double GetTime () { return NgProfiler::GetTime(timernr); }
+    long int GetCounts () { return NgProfiler::GetCounts(timernr); }
+    double GetMFlops ()
+    { return NgProfiler::GetFlops(timernr)
+        / NgProfiler::GetTime(timernr) * 1e-6; }
+    operator int () { return timernr; }
+  };
+
+
+  /**
+     Timer object.
+       Start / stop timer at constructor / destructor.
+  */
+  class RegionTimer
+  {
+    Timer & timer;
+  public:
+    /// start timer
+    RegionTimer (Timer & atimer) : timer(atimer) { timer.Start(); }
+    /// stop timer
+    ~RegionTimer () { timer.Stop(); }
+
+    RegionTimer() = delete;
+    RegionTimer(RegionTimer &&) = delete;
+    RegionTimer(const RegionTimer &) = delete;
+    void operator=(const RegionTimer &) = delete;
+    void operator=(RegionTimer &&) = delete;
+  };
+
+  class ThreadRegionTimer
+  {
+    size_t nr;
+    size_t tid;
+  public:
+    /// start timer
+    ThreadRegionTimer (size_t _nr, size_t _tid) : nr(_nr), tid(_tid)
+    { NgProfiler::StartThreadTimer(nr, tid); }
+    /// stop timer
+    ~ThreadRegionTimer ()
+    { NgProfiler::StopThreadTimer(nr, tid); }
+
+    ThreadRegionTimer() = delete;
+    ThreadRegionTimer(ThreadRegionTimer &&) = delete;
+    ThreadRegionTimer(const ThreadRegionTimer &) = delete;
+    void operator=(const ThreadRegionTimer &) = delete;
+    void operator=(ThreadRegionTimer &&) = delete;
+  };
+
+  class RegionTracer
+    {
+      int nr;
+      int thread_id;
+    public:
+      static constexpr int ID_JOB = PajeTrace::Task::ID_JOB;
+      static constexpr int ID_NONE = PajeTrace::Task::ID_NONE;
+      static constexpr int ID_TIMER = PajeTrace::Task::ID_TIMER;
+
+      RegionTracer() = delete;
+      RegionTracer(RegionTracer &&) = delete;
+      RegionTracer(const RegionTracer &) = delete;
+      void operator=(const RegionTracer &) = delete;
+      void operator=(RegionTracer &&) = delete;
+
+      /// start trace
+      RegionTracer (int athread_id, int region_id, int id_type = ID_NONE, int additional_value = -1 )
+        : thread_id(athread_id)
+        {
+	  if (trace)
+          nr = trace->StartTask (athread_id, region_id, id_type, additional_value);
+        }
+      /// start trace with timer
+      RegionTracer (int athread_id, Timer & timer, int additional_value = -1 )
+        : thread_id(athread_id)
+        {
+	  if (trace)
+          nr = trace->StartTask (athread_id, static_cast<int>(timer), ID_TIMER, additional_value);
+        }
+
+      /// set user defined value
+      void SetValue( int additional_value )
+      {
+	  if (trace)
+        trace->SetTask( thread_id, nr, additional_value );
+      }
+
+      /// stop trace
+      ~RegionTracer ()
+        {
+	  if (trace)
+          trace->StopTask (thread_id, nr);
+        }
+    };
+
+
+  // Helper function for timings
+  // Run f() at least min_iterations times until max_time seconds elapsed
+  // returns minimum runtime for a call of f()
+  template<typename TFunc>
+  double RunTiming( TFunc f, double max_time = 0.5, int min_iterations = 10 )
+  {
+      // Make sure the whole test run does not exceed maxtime
+      double tend = WallTime()+max_time;
+
+      // warmup
+      f();
+
+      double tres = std::numeric_limits<double>::max();
+      int iteration = 0;
+      while(WallTime()<tend || iteration++ < min_iterations)
+      {
+          double t = -WallTime();
+          f();
+          t += WallTime();
+          tres = std::min(tres, t);
+      }
+
+      return tres;
+  }
+
+} // namespace ngcore
+
+
+#endif // NETGEN_CORE_PROFILER_HPP

libsrc/core/utils.cpp

@@ -1,8 +1,10 @@
 #include "utils.hpp"
+#include "logging.hpp"
 
 #ifndef WIN32
 #include <cxxabi.h>
 #endif
+#include <iostream>
 
 namespace ngcore
 {
@@ -14,6 +16,24 @@ namespace ngcore
                                                                                       nullptr,
                                                                                       nullptr,
                                                                                       &status); }
+
+  double ticks_per_second = [] () noexcept
+  {
+      auto tick_start = GetTimeCounter();
+      double tstart = WallTime();
+      double tend = WallTime()+0.001;
+
+      // wait for 1ms and compare wall time with time counter
+      while(WallTime()<tend);
+
+      auto tick_end = GetTimeCounter();
+      tend = WallTime();
+
+      return (tick_end-tick_start)/(tend-tstart);
+  }();
+
+  const std::chrono::time_point<TClock> wall_time_start = TClock::now();
+
 } // namespace ngcore
 
 #endif

libsrc/core/utils.hpp

@@ -1,8 +1,10 @@
 #ifndef NETGEN_CORE_UTILS_HPP
 #define NETGEN_CORE_UTILS_HPP
 
-#include <string>
+#include <chrono>
 #include <sstream>
+#include <string>
+#include <x86intrin.h>   // for __rdtsc()  CPU time step counter
 
 #include "ngcore_api.hpp"       // for NGCORE_API
 
@@ -18,6 +20,35 @@ namespace ngcore
   inline bool unlikely (bool x) { return x; }
 #endif
 
+  using TClock = std::chrono::system_clock;
+  extern NGCORE_API const std::chrono::time_point<TClock> wall_time_start;
+
+  // Time in seconds since program start
+  inline double WallTime () noexcept
+  {
+      std::chrono::time_point<TClock> now = TClock::now();
+      std::chrono::duration<double> elapsed_seconds = now-wall_time_start;
+      return elapsed_seconds.count();
+  }
+
+  // High precision clock counter register
+  using TTimePoint = size_t;
+  extern NGCORE_API double ticks_per_second;
+
+  inline TTimePoint GetTimeCounter() noexcept
+  {
+      return TTimePoint(__rdtsc());
+  }
+
+  template <class T>
+  inline std::string ToString (const T& t)
+  {
+      std::stringstream ss;
+      ss << t;
+      return ss.str();
+  }
+
+
 } // namespace ngcore
 
 #endif // NETGEN_CORE_UTILS_HPP

libsrc/general/ngpython.hpp

@@ -66,16 +66,7 @@ namespace netgen
     return static_cast<typename function_traits<Function>::pointer>(lambda);
   }
 
-
+} // namespace netgen
-  template <class T>
-  inline std::string ToString (const T& t)
-  {
-    std::stringstream ss;
-    ss << t;
-    return ss.str();
-  }
-
-}
 
 #endif