Paje tracing

libsrc/core/CMakeLists.txt

@@ -1,5 +1,5 @@
 
-add_library(ngcore SHARED archive.cpp logging.cpp)
+add_library(ngcore SHARED archive.cpp logging.cpp paje_trace.cpp utils.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
+  exception.hpp symboltable.hpp paje_trace.hpp utils.hpp
   DESTINATION ${NG_INSTALL_DIR_INCLUDE}/core COMPONENT netgen_devel)
 
 if(ENABLE_CPP_CORE_GUIDELINES_CHECK)

libsrc/core/archive.cpp

@@ -19,16 +19,6 @@ namespace ngcore
   void SetLibraryVersion(const std::string& library, const VersionInfo& version)
   { library_versions[library] = version; }
 
-#ifdef WIN32
-  // windows does demangling in typeid(T).name()
-  std::string Demangle(const char* typeinfo) { return typeinfo; }
-#else
-  std::string Demangle(const char* typeinfo) { int status; return abi::__cxa_demangle(typeinfo,
-                                                                                      nullptr,
-                                                                                      nullptr,
-                                                                                      &status); }
-#endif
-
   // clang-tidy should ignore this static object
   static std::unique_ptr<std::map<std::string, detail::ClassArchiveInfo>> type_register;  // NOLINT
   const detail::ClassArchiveInfo& Archive :: GetArchiveRegister(const std::string& classname)

libsrc/core/archive.hpp

@@ -15,8 +15,9 @@
 
 #include "exception.hpp"        // for UnreachableCodeException, Exception
 #include "logging.hpp"          // for logger
-#include "ngcore_api.hpp"       // for NGCORE_API, unlikely
+#include "ngcore_api.hpp"       // for NGCORE_API
 #include "type_traits.hpp"      // for all_of_tmpl
+#include "utils.hpp"            // for Demangle, unlikely
 #include "version.hpp"          // for VersionInfo
 
 #ifdef NETGEN_PYTHON
@@ -28,7 +29,6 @@ namespace ngcore
   // Libraries using this archive can store their version here to implement backwards compatibility
   NGCORE_API const VersionInfo& GetLibraryVersion(const std::string& library);
   NGCORE_API void SetLibraryVersion(const std::string& library, const VersionInfo& version);
-  NGCORE_API std::string Demangle(const char* typeinfo);
 
   class NGCORE_API Archive;
 

libsrc/core/logging.hpp

@@ -26,23 +26,6 @@
 namespace spdlog
 {
   // Dummys if Netgen is compiled with USE_SPDLOG=OFF.
-  class logger
-  {
-  public:
-    template<typename T>
-    void trace(const T& /*unused*/) {}
-    template<typename T>
-    void debug(const T& /*unused*/) {}
-    template<typename T>
-    void info(const T& text) { std::cout << text << std::endl; }
-    template<typename T>
-    void warn(const T& text) { std::cout << text << std::endl; }
-    template<typename T>
-    void error(const T& text) { std::cout << text << std::endl; }
-    template<typename T>
-    void critical(const T& text) { std::cout << text << std::endl; }
-  };
-
   namespace level
   {
     enum level_enum
@@ -57,6 +40,42 @@ namespace spdlog
       };
   } // namespace level
 
+  class logger
+  {
+  public:
+    template<typename T>
+    void log_helper( T t) { std::clog << t; }
+
+    template<typename T, typename ... Args>
+    void log_helper( T t, Args ... args)
+    {
+        std::clog << t;
+        log_helper(args...);
+        std::clog << ", ";
+    }
+
+    template<typename ... Args>
+    void log( level::level_enum level, const char* fmt, Args ... args)
+    {
+        std::clog << level << ": " << fmt << "\t Arguments: ";
+        log_helper(args...);
+        std::clog << "\n";
+    }
+
+    template<typename ... Args>
+    void trace( const char* fmt, Args ... args) { log(level::level_enum::trace, fmt, args...); }
+    template<typename ... Args>
+    void debug( const char* fmt, Args ... args) { log(level::level_enum::debug, fmt, args...); }
+    template<typename ... Args>
+    void info( const char* fmt, Args ... args) { log(level::level_enum::info, fmt, args...); }
+    template<typename ... Args>
+    void warn( const char* fmt, Args ... args) { log(level::level_enum::warn, fmt, args...); }
+    template<typename ... Args>
+    void error( const char* fmt, Args ... args) { log(level::level_enum::err, fmt, args...); }
+    template<typename ... Args>
+    void critical( const char* fmt, Args ... args) { log(level::level_enum::critical, fmt, args...); }
+  };
+
   namespace sinks
   {
     class sink {};

libsrc/core/ngcore_api.hpp

@@ -15,15 +15,23 @@
         #define NGCORE_API NGCORE_API_IMPORT
 #endif
 
-namespace ngcore
+#ifdef __INTEL_COMPILER
-{
+  #ifdef WIN32
-#if defined(__GNUC__)
+    #define NETGEN_INLINE __forceinline inline
-  inline bool likely (bool x) { return bool(__builtin_expect(long(x), 1L)); }
+    #define NETGEN_LAMBDA_INLINE
-  inline bool unlikely (bool x) { return bool(__builtin_expect(long(x), 0L)); }
+  #else
+    #define NETGEN_INLINE __forceinline inline
+    #define NETGEN_LAMBDA_INLINE __attribute__ ((__always_inline__))
+  #endif
 #else
-  inline bool likely (bool x) { return x; }
+  #ifdef __GNUC__
-  inline bool unlikely (bool x) { return x; }
+    #define NETGEN_INLINE __attribute__ ((__always_inline__)) inline
+    #define NETGEN_LAMBDA_INLINE __attribute__ ((__always_inline__))
+    #define NETGEN_VLA
+  #else
+    #define NETGEN_INLINE inline
+    #define NETGEN_LAMBDA_INLINE
+  #endif
 #endif
-} // namespace ngcore
 
 #endif // NETGEN_CORE_NGCORE_API_HPP

libsrc/core/paje_trace.cpp

@@ -0,0 +1,659 @@
+#include <algorithm>
+#include <atomic>
+#include <map>
+#include <set>
+#include <thread>
+#include <iostream>
+
+#include "archive.hpp"           // for Demangle
+#include "paje_trace.hpp"
+
+static constexpr int MAX_TRACE_LINE_SIZE = 50;
+extern const char *header;
+
+namespace ngcore
+{
+  // Produce no traces by default
+  size_t PajeTrace::max_tracefile_size = 11110000;
+
+  // If true, produce variable counting active threads
+  // increases trace by a factor of two
+  bool PajeTrace::trace_thread_counter = true;
+  bool PajeTrace::trace_threads = true;
+
+  PajeTrace :: PajeTrace(int anthreads, std::string aname)
+  {
+    start_time = GetTime();
+
+    nthreads = anthreads;
+    tracefile_name = 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);
+    if(max_num_events_per_thread>0)
+    {
+      logger->info( "Tracefile size = {}MB", max_tracefile_size/1024/1024);
+      logger->info( "Tracing {} events per thread", max_num_events_per_thread , " events per thread");
+    }
+
+    tasks.resize(nthreads);
+    int reserve_size = std::min(1000000U, max_num_events_per_thread);
+    for(auto & t : tasks)
+        t.reserve(reserve_size);
+
+    links.resize(nthreads);
+    for(auto & l : links)
+      l.reserve(reserve_size);
+
+    jobs.reserve(reserve_size);
+    timer_events.reserve(reserve_size);
+
+    tracing_enabled = true;
+  }
+
+  PajeTrace :: ~PajeTrace()
+  {
+    if(tracefile_name.size()>0)
+      Write(tracefile_name);
+  }
+
+
+  void PajeTrace::StopTracing()
+    {
+      if(tracing_enabled && max_num_events_per_thread>0)
+        {
+          logger->warn("Maximum number of traces reached, tracing is stopped now.");
+        }
+      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;
+          if(x<d)
+            r=1, g=6*x,b=0;
+          else if (x<2*d)
+            r=1.0-6*(x-d),g=1,b=0;
+          else if (x<3*d)
+            r=0, g=1,b=6*(x-2*d);
+          else if (x<4*d)
+            r=0, g=1-6*(x-3*d),b=1;
+          else if (x<5*d)
+            r=6*(x-4*d), g=0,b=1;
+          else
+            r=1, g=0,b=1-5*(x-d);
+        };
+
+      int alias_counter;
+
+      FILE * ctrace_stream;
+      TTimePoint start_time;
+      std::shared_ptr<spdlog::logger> logger = GetLogger("PajeTrace");
+
+
+      double ConvertTime(TTimePoint t) {
+          // return time in milliseconds as double
+        // return std::chrono::duration<double>(t-start_time).count()*1000.0;
+        // return std::chrono::duration<double>(t-start_time).count() / 2.7e3;
+        return (t-start_time) / 2.7e6;
+      }
+
+      enum PType
+        {
+          SET_VARIABLE=1,
+          ADD_VARIABLE,
+          SUB_VARIABLE,
+          PUSH_STATE,
+          POP_STATE,
+          START_LINK,
+          STOP_LINK
+        };
+
+      struct PajeEvent
+        {
+          PajeEvent( int aevent_type, double atime, int atype, int acontainer, double avar_value )
+            : time(atime), var_value(avar_value), event_type(aevent_type), type(atype), container(acontainer)
+            { }
+
+          PajeEvent( int aevent_type, double atime, int atype, int acontainer, int avalue = 0, int aid = 0, bool avalue_is_alias = true )
+            : time(atime), event_type(aevent_type), type(atype), container(acontainer), value(avalue), id(aid), value_is_alias(avalue_is_alias)
+            { }
+
+          PajeEvent( int aevent_type, double atime, int atype, int acontainer, int avalue, int astart_container, int akey )
+            : time(atime), event_type(aevent_type), type(atype), container(acontainer), value(avalue), start_container(astart_container), id(akey)
+            { }
+
+          double time;
+          double var_value = 0.0;
+          int event_type;
+          int type;
+          int container;
+          int value = 0;
+          int start_container = 0;
+          int id = 0;
+          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)
+              if(time == other.time)
+                return event_type < other.event_type;
+              else
+                return (time < other.time);
+          }
+
+          int write(char *buf)
+            {
+              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 );
+                case PajeAddVariable:
+                  return sprintf( buf, "%d\t%.15g\ta%d\ta%d\t%.15g\n", PajeAddVariable, time, type, container, var_value );
+                case PajeSubVariable:
+                  return sprintf( buf, "%d\t%.15g\ta%d\ta%d\t%.15g\n", PajeSubVariable, time, type, container, var_value );
+                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);
+                  else
+                    return sprintf( buf, "%d\t%.15g\ta%d\ta%d\t%d\t%d\n", PajePushState, time, type, container, value, id);
+                case PajePopState:
+                  return sprintf( buf, "%d\t%.15g\ta%d\ta%d\n", PajePopState, time, type, container );
+                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 );
+                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 0;
+            }
+        };
+
+      std::vector<PajeEvent> events;
+
+    public:
+      PajeFile( string filename, TTimePoint astart_time )
+        {
+          start_time = astart_time;
+          ctrace_stream = fopen (filename.c_str(),"w");
+          fprintf(ctrace_stream, "%s", header );
+          alias_counter = 0;
+        }
+      int DefineContainerType ( int parent_type, 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() );
+          else
+            fprintf( ctrace_stream, "%d\ta%d\t%d\t\"%s\"\n", PajeDefineContainerType, alias, parent_type, name.c_str() );
+          return alias;
+        }
+
+      int DefineVariableType ( int container_type, 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() );
+          return alias;
+        }
+
+      int DefineStateType ( int type, string name )
+        {
+          int alias = ++alias_counter;
+          fprintf( ctrace_stream, "%d\ta%d\ta%d\t\"%s\"\n", PajeDefineStateType, alias, type, name.c_str() );
+          return alias;
+        }
+
+      //       int DefineEventType ()
+      //         {
+      //           Write("event not implemented");
+      //         }
+
+      int DefineLinkType (int parent_container_type, int start_container_type, int stop_container_type, 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() );
+          return alias;
+        }
+
+      int DefineEntityValue (int type, string name, double hue = -1)
+        {
+          if(hue==-1)
+            {
+              std::hash<string> shash;
+              size_t h = shash(name);
+              h ^= h>>32;
+              h = (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 );
+          return alias;
+        }
+
+      int CreateContainer ( int type, int parent, 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() );
+          else
+            fprintf( ctrace_stream, "%d\t0\ta%d\ta%d\t%d\t\"%s\"\n", PajeCreateContainer, alias, type, parent, name.c_str() );
+          return alias;
+        }
+      void DestroyContainer ()
+        {}
+
+      void SetVariable (TTimePoint time, int type, int container, double value )
+        {
+          events.push_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 ) );
+        }
+
+      void SubVariable (TTimePoint time, int type, int container, double value )
+        {
+          events.push_back( PajeEvent( PajeSubVariable, ConvertTime(time), type, container, value ) );
+        }
+
+      void SetState ()
+        {}
+
+      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) );
+        }
+
+      void PopState ( TTimePoint time, int type, int container )
+        {
+          events.push_back( PajeEvent( PajePopState, ConvertTime(time), type, container ) );
+        }
+
+      void ResetState ()
+        {}
+
+      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 ) );
+        }
+
+      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 ) );
+        }
+
+      void NewEvent ()
+        {}
+
+      void WriteEvents()
+        {
+          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++)
+          {
+              events[i].write( buf );
+              fprintf( ctrace_stream, "%s", buf );
+          }
+          logger->info("Done");
+        }
+
+    private:
+      enum
+        {
+          PajeDefineContainerType = 0,
+          PajeDefineVariableType = 1,
+          PajeDefineStateType = 2,
+          PajeDefineEventType = 3,
+          PajeDefineLinkType = 4,
+          PajeDefineEntityValue = 5,
+          PajeCreateContainer = 6,
+          PajeDestroyContainer = 7,
+          PajeSetVariable = 8,
+          PajeAddVariable = 9,
+          PajeSubVariable = 10,
+          PajeSetState = 11,
+          PajePushState = 12,
+          PajePopState = 13,
+          PajeResetState = 14,
+          PajeStartLink = 15,
+          PajeEndLink = 16,
+          PajeNewEvent = 17
+        };
+
+    };
+
+  NGCORE_API PajeTrace *trace;
+
+  void PajeTrace::Write( string filename )
+    {
+      int n_events = jobs.size() + timer_events.size();
+      for(auto & vtasks : tasks)
+        n_events += vtasks.size();
+
+      logger->info("{} events traced",  n_events);
+
+      if(n_events==0)
+        {
+          logger->info("No data traced, skip writing trace file");
+          return;
+        }
+
+      if(!tracing_enabled)
+        {
+            logger->warning("Tracing stopped during computation due to tracefile size limit of {} megabytes.", max_tracefile_size/1024/1024);
+        }
+
+      PajeFile paje(filename, start_time);
+
+      const int container_type_task_manager = paje.DefineContainerType( 0, "Task Manager" );
+      const int container_type_node = paje.DefineContainerType( container_type_task_manager, "Node");
+      const int container_type_thread = paje.DefineContainerType( container_type_task_manager, "Thread");
+      const int container_type_timer = container_type_thread; //paje.DefineContainerType( container_type_task_manager, "Timers");
+      const int container_type_jobs = paje.DefineContainerType( container_type_task_manager, "Jobs");
+
+      const int state_type_job = paje.DefineStateType( container_type_jobs, "Job" );
+      const int state_type_task = paje.DefineStateType( container_type_thread, "Task" );
+      const int state_type_timer = paje.DefineStateType( container_type_timer, "Timer state" );
+
+      const int variable_type_active_threads = paje.DefineVariableType( container_type_jobs, "Active threads" );
+
+      const int container_task_manager = paje.CreateContainer( container_type_task_manager, 0, "The task manager" );
+      const int container_jobs = paje.CreateContainer( container_type_jobs, container_task_manager, "Jobs" );
+      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;
+
+      for(int i=0; i<num_nodes; i++)
+          container_nodes.push_back( paje.CreateContainer( container_type_node, container_task_manager, "Node " /* TODO: + ToString(i) */));
+
+      std::vector <int> thread_aliases;
+      if(trace_threads)
+        for (int i=0; i<nthreads; i++)
+          {
+            char name[20];
+            sprintf(name, "Thread %d", i);
+            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;
+      std::map<const std::type_info *, int> job_task_map;
+
+      for(Job & j : jobs)
+        if(job_map.find(j.type) == job_map.end())
+          {
+            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 );
+          }
+
+      for(Job & j : jobs)
+        {
+          paje.PushState( j.start_time, state_type_job, container_jobs, job_map[j.type] );
+          paje.PopState( j.stop_time, state_type_job, container_jobs );
+        }
+
+      std::set<int> timer_ids;
+      std::map<int,int> timer_aliases;
+
+      for(auto & event : timer_events)
+        timer_ids.insert(event.timer_id);
+
+
+      for(auto & vtasks : tasks)
+        for (Task & t : vtasks)
+          if(t.id_type==Task::ID_TIMER)
+            timer_ids.insert(t.id);
+
+      for(auto id : timer_ids)
+        timer_aliases[id] = paje.DefineEntityValue( state_type_timer, "a timer" /* TODO: NgProfiler::GetName(id).c_str()*/, -1 );
+
+      int timerdepth = 0;
+      int maxdepth = 0;
+      for(auto & event : timer_events)
+        {
+          if(event.is_start)
+            {
+              timerdepth++;
+              maxdepth = timerdepth>maxdepth ? timerdepth : maxdepth;
+            }
+          else
+            timerdepth--;
+        }
+
+      std::vector<int> timer_container_aliases;
+      timer_container_aliases.resize(maxdepth);
+      for(int i=0; i<maxdepth; i++)
+        {
+          char name[30];
+          sprintf(name, "Timer level %d", i);
+          timer_container_aliases[i] =  paje.CreateContainer( container_type_timer, container_task_manager, name );
+        }
+
+      timerdepth = 0;
+      for(auto & event : timer_events)
+        {
+          if(event.is_start)
+            paje.PushState( event.time, state_type_timer, timer_container_aliases[timerdepth++], timer_aliases[event.timer_id] );
+          else
+            paje.PopState( event.time, state_type_timer, timer_container_aliases[--timerdepth] );
+        }
+
+      for(auto & vtasks : tasks)
+        {
+          for (Task & t : vtasks) {
+              int value_id = t.id;
+
+              switch(t.id_type)
+                {
+                case Task::ID_JOB:
+                  value_id = job_task_map[jobs[t.id-1].type];
+                  if(trace_thread_counter)
+                    {
+                      paje.AddVariable( t.start_time, variable_type_active_threads, container_jobs, 1.0 );
+                      paje.SubVariable( t.stop_time, variable_type_active_threads, container_jobs, 1.0 );
+                    }
+                  if(trace_threads)
+                    {
+                      paje.PushState( t.start_time, state_type_task, thread_aliases[t.thread_id], value_id, t.additional_value, true );
+                      paje.PopState( t.stop_time, state_type_task, thread_aliases[t.thread_id] );
+                    }
+                  break;
+                case Task::ID_TIMER:
+                  value_id = timer_aliases[t.id];
+                  paje.PushState( t.start_time, state_type_timer, thread_aliases[t.thread_id], value_id, t.additional_value, true );
+                  paje.PopState( t.stop_time, state_type_timer, thread_aliases[t.thread_id] );
+                  break;
+                default:
+                  paje.PushState( t.start_time, state_type_task, thread_aliases[t.thread_id], value_id, t.additional_value, false );
+                  paje.PopState( t.stop_time, state_type_task, thread_aliases[t.thread_id] );
+                  break;
+                }
+          }
+        }
+
+      // Merge link event
+      int nlinks = 0;
+      for( auto & l : links)
+        nlinks += l.size();
+
+      std::vector<ThreadLink> links_merged;
+      links_merged.reserve(nlinks);
+      std::vector<unsigned int> pos(nthreads);
+
+      int nlinks_merged = 0;
+      while(nlinks_merged < nlinks)
+        {
+          int minpos = -1;
+          TTimePoint mintime;
+          for (int t = 0; t<nthreads; t++)
+            {
+              if(pos[t] < links[t].size() && (links[t][pos[t]].time < mintime || minpos==-1))
+                {
+                  minpos = t;
+                  mintime = links[t][pos[t]].time;
+                }
+            }
+          links_merged.push_back( links[minpos][pos[minpos]] );
+          pos[minpos]++;
+          nlinks_merged++;
+        }
+
+      std::vector<ThreadLink> started_links;
+
+      int link_type = paje.DefineLinkType(container_type_node, container_type_thread, container_type_thread, "links");
+
+      // match links
+      for ( auto & l : links_merged )
+        {
+          if(l.is_start)
+            {
+              started_links.push_back(l);
+            }
+          else
+            {
+              unsigned int i = 0;
+              while(i<started_links.size())
+                {
+                  while(i<started_links.size() && started_links[i].key == l.key)
+                    {
+                      ThreadLink & sl = started_links[i];
+                      // Avoid links on same thread
+                      if(sl.thread_id != l.thread_id)
+                        {
+                          paje.StartLink( sl.time, link_type, container_nodes[sl.thread_id*num_nodes/nthreads], l.key, thread_aliases[sl.thread_id], l.key);
+                          paje.EndLink(    l.time, link_type, container_nodes[l.thread_id*num_nodes/nthreads], l.key, thread_aliases[l.thread_id], l.key);
+                        }
+                      started_links.erase(started_links.begin()+i);
+                    }
+                  i++;
+                }
+            }
+        }
+      paje.WriteEvents();
+    }
+}
+
+const char *header =
+        "%EventDef PajeDefineContainerType 0 \n"
+        "%       Alias string \n"
+        "%       Type string \n"
+        "%       Name string \n"
+        "%EndEventDef \n"
+        "%EventDef PajeDefineVariableType 1 \n"
+        "%       Alias string \n"
+        "%       Type string \n"
+        "%       Name string \n"
+        "%       Color color \n"
+        "%EndEventDef \n"
+        "%EventDef PajeDefineStateType 2 \n"
+        "%       Alias string \n"
+        "%       Type string \n"
+        "%       Name string \n"
+        "%EndEventDef \n"
+        "%EventDef PajeDefineEventType 3 \n"
+        "%       Alias string \n"
+        "%       Type string \n"
+        "%       Name string \n"
+        "%       Color color \n"
+        "%EndEventDef \n"
+        "%EventDef PajeDefineLinkType 4 \n"
+        "%       Alias string \n"
+        "%       Type string \n"
+        "%       StartContainerType string \n"
+        "%       EndContainerType string \n"
+        "%       Name string \n"
+        "%EndEventDef \n"
+        "%EventDef PajeDefineEntityValue 5 \n"
+        "%       Alias string \n"
+        "%       Type string \n"
+        "%       Name string \n"
+        "%       Color color \n"
+        "%EndEventDef \n"
+        "%EventDef PajeCreateContainer 6 \n"
+        "%       Time date \n"
+        "%       Alias string \n"
+        "%       Type string \n"
+        "%       Container string \n"
+        "%       Name string \n"
+        "%EndEventDef \n"
+        "%EventDef PajeDestroyContainer 7 \n"
+        "%       Time date \n"
+        "%       Type string \n"
+        "%       Name string \n"
+        "%EndEventDef \n"
+        "%EventDef PajeSetVariable 8 \n"
+        "%       Time date \n"
+        "%       Type string \n"
+        "%       Container string \n"
+        "%       Value double \n"
+        "%EndEventDef\n"
+        "%EventDef PajeAddVariable 9 \n"
+        "%       Time date \n"
+        "%       Type string \n"
+        "%       Container string \n"
+        "%       Value double \n"
+        "%EndEventDef\n"
+        "%EventDef PajeSubVariable 10 \n"
+        "%       Time date \n"
+        "%       Type string \n"
+        "%       Container string \n"
+        "%       Value double \n"
+        "%EndEventDef\n"
+        "%EventDef PajeSetState 11 \n"
+        "%       Time date \n"
+        "%       Type string \n"
+        "%       Container string \n"
+        "%       Value string \n"
+        "%EndEventDef\n"
+        "%EventDef PajePushState 12 \n"
+        "%       Time date \n"
+        "%       Type string \n"
+        "%       Container string \n"
+        "%       Value string \n"
+        "%       Id string \n"
+        "%EndEventDef\n"
+        "%EventDef PajePopState 13 \n"
+        "%       Time date \n"
+        "%       Type string \n"
+        "%       Container string \n"
+        "%EndEventDef\n"
+        "%EventDef PajeResetState 14 \n"
+        "%       Time date \n"
+        "%       Type string \n"
+        "%       Container string \n"
+        "%EndEventDef\n"
+        "%EventDef PajeStartLink 15 \n"
+        "%       Time date \n"
+        "%       Type string \n"
+        "%       Container string \n"
+        "%       Value string \n"
+        "%       StartContainer string \n"
+        "%       Key string \n"
+        "%EndEventDef\n"
+        "%EventDef PajeEndLink 16 \n"
+        "%       Time date \n"
+        "%       Type string \n"
+        "%       Container string \n"
+        "%       Value string \n"
+        "%       EndContainer string \n"
+        "%       Key string \n"
+        "%EndEventDef\n"
+        "%EventDef PajeNewEvent 17 \n"
+        "%       Time date \n"
+        "%       Type string \n"
+        "%       Container string \n"
+        "%       Value string \n"
+        "%EndEventDef\n";

libsrc/core/paje_trace.hpp

@@ -0,0 +1,215 @@
+#ifndef NETGEN_CORE_PAJE_TRACE_HPP
+#define NETGEN_CORE_PAJE_TRACE_HPP
+
+#include <limits>
+#include <vector>
+#include <x86intrin.h>   // for __rdtsc()  CPU time step counter
+
+#include "ngcore_api.hpp"    // for NGCORE_API
+#include "logging.hpp"       // for logger
+
+namespace ngcore
+{
+
+  extern NGCORE_API class PajeTrace *trace;
+  class PajeTrace
+    {
+    public:
+      typedef std::chrono::system_clock TClock;
+      // 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;
+
+      bool tracing_enabled;
+      TTimePoint start_time;
+      int nthreads;
+
+    public:
+
+      // Approximate number of events to trace. Tracing will
+      // be stopped if any thread reaches this number of events
+      unsigned int max_num_events_per_thread;
+
+      static void SetTraceThreads( bool atrace_threads )
+        {
+          trace_threads = atrace_threads;
+        }
+
+      static void SetTraceThreadCounter( bool trace_threads )
+        {
+          trace_thread_counter = trace_threads;
+        }
+
+      static void SetMaxTracefileSize( size_t max_size )
+        {
+          max_tracefile_size = max_size;
+        }
+
+      std::string tracefile_name;
+
+      struct Job
+        {
+          int job_id;
+          const std::type_info *type;
+          TTimePoint start_time;
+          TTimePoint stop_time;
+        };
+
+      struct Task
+        {
+          int thread_id;
+
+          int id;
+          int id_type;
+
+          int additional_value;
+
+          TTimePoint start_time;
+          TTimePoint stop_time;
+
+          static constexpr int ID_NONE = -1;
+          static constexpr int ID_JOB = 1;
+          static constexpr int ID_TIMER = 2;
+        };
+
+      struct TimerEvent
+        {
+          int timer_id;
+          TTimePoint time;
+          bool is_start;
+          int thread_id;
+
+          bool operator < (const TimerEvent & other) const { return time < other.time; }
+        };
+
+      struct ThreadLink
+        {
+          int thread_id;
+          int key;
+          TTimePoint time;
+          bool is_start;
+          bool operator < (const ThreadLink & other) const { return time < other.time; }
+        };
+
+      std::vector<std::vector<Task> > tasks;
+      std::vector<Job> jobs;
+      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(int anthreads, std::string aname = "");
+      ~PajeTrace();
+
+      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});
+        }
+
+      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});
+        }
+
+      NETGEN_INLINE int StartTask(int thread_id, int id, int id_type = Task::ID_NONE, int additional_value = -1)
+        {
+          if(!tracing_enabled) return -1;
+          if(!trace_threads && !trace_thread_counter) return -1;
+	  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()} );
+          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();
+        }
+
+      void SetTask(int thread_id, int task_num, int additional_value) {
+          if(!trace_threads && !trace_thread_counter) return;
+          if(task_num>=0)
+            tasks[thread_id][task_num].additional_value = additional_value;
+      }
+
+      void StartJob(int job_id, const std::type_info & type)
+        {
+          if(!tracing_enabled) return;
+          if(jobs.size() == max_num_events_per_thread)
+            StopTracing();
+          jobs.push_back( Job{job_id, &type, GetTime()} );
+        }
+
+      void StopJob()
+        {
+          if(tracing_enabled)
+            jobs.back().stop_time = GetTime();
+        }
+
+      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} );
+        }
+
+      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} );
+        }
+
+      void Write( 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;
+        }
+    };
+}
+
+#endif // NETGEN_CORE_PAJE_TRACE_HPP

libsrc/core/utils.cpp

@@ -0,0 +1,20 @@
+#include "utils.hpp"
+
+#ifndef WIN32
+#include <cxxabi.h>
+#endif
+
+namespace ngcore
+{
+#ifdef WIN32
+  // windows does demangling in typeid(T).name()
+  NGCORE_API std::string Demangle(const char* typeinfo) { return typeinfo; }
+#else
+  NGCORE_API std::string Demangle(const char* typeinfo) { int status; return abi::__cxa_demangle(typeinfo,
+                                                                                      nullptr,
+                                                                                      nullptr,
+                                                                                      &status); }
+} // namespace ngcore
+
+#endif
+

libsrc/core/utils.hpp

@@ -0,0 +1,23 @@
+#ifndef NETGEN_CORE_UTILS_HPP
+#define NETGEN_CORE_UTILS_HPP
+
+#include <string>
+#include <sstream>
+
+#include "ngcore_api.hpp"       // for NGCORE_API
+
+namespace ngcore
+{
+  NGCORE_API std::string Demangle(const char* typeinfo);
+
+#if defined(__GNUC__)
+  inline bool likely (bool x) { return bool(__builtin_expect(long(x), 1L)); }
+  inline bool unlikely (bool x) { return bool(__builtin_expect(long(x), 0L)); }
+#else
+  inline bool likely (bool x) { return x; }
+  inline bool unlikely (bool x) { return x; }
+#endif
+
+} // namespace ngcore
+
+#endif // NETGEN_CORE_UTILS_HPP