added a profiler to measure the cpu time used in each thread

include/Application.h

@@ -19,6 +19,7 @@
 #include "Flags.h"
 #include "InternalModule.h"
 #include "EntityOwner.h"
+#include "Profiler.h"
 
 namespace ChimeraTK {
 
@@ -130,6 +131,13 @@ namespace ChimeraTK {
         thread_local static std::string name{"**UNNAMED**"};
         return name;
       }
+      
+      /** Register the thread in the application system and give it a name. This should be done for all threads used by
+       *  the application to help with debugging and to allow profiling. */
+      static void registerThread(const std::string &name) {
+        threadName() = name;
+        Profiler::registerThread(name);
+      }
 
     protected:
 

include/ArrayAccessor.h

@@ -83,6 +83,12 @@ namespace ChimeraTK {
         node.addTag(tag);
       }
       
+      void read() {
+        Profiler::stopMeasurement();
+        mtca4u::OneDRegisterAccessor<UserType>::read();
+        Profiler::startMeasurement();
+      }
+      
   protected:
       ArrayAccessor(Module *owner, const std::string &name, VariableDirection direction, std::string unit,
           size_t nElements, UpdateMode mode, const std::string &description,

include/Profiler.h

+/*
+ * Profiler.h
+ *
+ *  Created on: May 15, 2017
+ *      Author: Martin Hierholzer
+ */
+
+#ifndef CHIMERATK_PROFILER_H
+#define CHIMERATK_PROFILER_H
+
+#include <string>
+#include <atomic>
+#include <chrono>
+#include <list>
+#include <mutex>
+#include <assert.h>
+
+namespace ChimeraTK {
+  
+  class Profiler {
+    
+    public:
+      
+      class ThreadData {
+        
+        public:
+          
+          /** Return the name of the thread */
+          const std::string& getName() const { return name; }
+          
+          /** Return the integrated active time of the thread in microseconds. */
+          uint64_t getIntegratedTime() const { return integratedTime; }
+
+          /** Return the integrated active time of the thread in microseconds and atomically reset the counter to 0. */
+          uint64_t getAndResetIntegratedTime() {
+            uint64_t time = integratedTime;
+            integratedTime.fetch_sub(time);
+            return time;
+          }
+          
+        private:
+          
+          friend class Profiler;
+          
+          /** Copy of Application::threadName(), stored here to make it accessible outside the thread */
+          std::string name;
+          
+          /** Reference point for the time measurement */
+          std::chrono::high_resolution_clock::time_point lastActiated;
+          
+          /** Flag whether this thread is currently active */
+          bool isActive{false};
+
+          /** Integrated time this thread was active in microseconds */
+          std::atomic<uint64_t> integratedTime;
+          
+      };
+    
+      /** Register a thread in the profiler. This function must be called in each thread before calling
+       *  startMeasurement() and stopMeasurement() in the same thread. The function must not be called twice in the
+       *  same thread. The call to this function implicitly triggers starting the time measurement
+       *  (see startMeasurement()) */
+      static void registerThread(const std::string &name) {
+        getThreadData().name = name;
+        std::lock_guard<std::mutex> lock(threadDataList_mutex);
+        threadDataList.emplace_back(&getThreadData());
+        startMeasurement();
+      }
+      
+      /** Obtain a list of ThreadData references for all threads registered with the profiler. */
+      static const std::list<ThreadData*>& getDataList() {
+        return threadDataList;
+      }
+      
+      /** Start the time measurement for the current thread. Call this immediately after the thread woke up e.g. from
+       *  blocking read. */
+      static void startMeasurement() {
+        assert(getThreadData().isActive == false);
+        getThreadData().isActive = true;
+        getThreadData().lastActiated = std::chrono::high_resolution_clock::now();
+      }
+      
+      /** Stop the time measurement for the current thread. Call this right before putting the thread to sleep e.g.
+       *  before a blocking read. */
+      static void stopMeasurement() {
+        if(!getThreadData().isActive) return;
+        getThreadData().isActive = false;
+        auto duration = std::chrono::high_resolution_clock::now() - getThreadData().lastActiated;
+        getThreadData().integratedTime += std::chrono::duration_cast<std::chrono::microseconds>(duration).count();
+      }
+      
+    private:
+
+      /** Return the ThreadData object associated with the current thread. */
+      static ThreadData& getThreadData() {
+        thread_local static ThreadData data;
+        return data;
+      }
+
+      /** List of ThreadData references registered with the profiler.  */
+      static std::list<ThreadData*> threadDataList;
+
+      /** Mutex for write access to the threadDataList member. Access to existing list entries through the public
+       *  member functions of ThreadData is allowed without holding this mutex. */
+      static std::mutex threadDataList_mutex;
+      
+  };
+
+}
+
+#endif /* CHIMERATK_PROFILER_H */

include/ScalarAccessor.h

@@ -83,6 +83,12 @@ namespace ChimeraTK {
         node.addTag(tag);
       }
       
+      void read() {
+        Profiler::stopMeasurement();
+        mtca4u::ScalarRegisterAccessor<UserType>::read();
+        Profiler::startMeasurement();
+      }
+      
   protected:
 
       ScalarAccessor(Module *owner, const std::string &name, VariableDirection direction, std::string unit,

include/ThreadedFanOut.h

@@ -47,12 +47,14 @@ namespace ChimeraTK {
 
       /** Synchronise feeder and the consumers. This function is executed in the separate thread. */
       void run() {
-        Application::getInstance().threadName() = "ThreadedFanOut "+FanOut<UserType>::impl->getName();
+        Application::registerThread("ThreadedFanOut "+FanOut<UserType>::impl->getName());
         Application::testableModeLock("start");
         while(true) {
           // receive data
           boost::this_thread::interruption_point();
+          Profiler::stopMeasurement();
           FanOut<UserType>::impl->read();
+          Profiler::startMeasurement();
           boost::this_thread::interruption_point();
           // send out copies to slaves
           for(auto &slave : FanOut<UserType>::slaves) {

include/TriggerFanOut.h

@@ -15,6 +15,7 @@
 #include "Application.h"
 #include "FeedingFanOut.h"
 #include "InternalModule.h"
+#include "Profiler.h"
 
 namespace ChimeraTK {
   
@@ -58,12 +59,14 @@ namespace ChimeraTK {
 
       /** Synchronise feeder and the consumers. This function is executed in the separate thread. */
       void run() {
-        Application::getInstance().threadName() = "TriggerFanOut "+externalTrigger->getName();
+        Application::registerThread("TriggerFanOut "+externalTrigger->getName());
         Application::testableModeLock("start");
         while(true) {
           // wait for external trigger
           boost::this_thread::interruption_point();
+          Profiler::stopMeasurement();
           externalTrigger->read();
+          Profiler::startMeasurement();
           boost::this_thread::interruption_point();
           // receive data
           transferGroup.read();

src/ApplicationModule.cc

@@ -36,7 +36,7 @@ namespace ChimeraTK {
 /*********************************************************************************************************************/
 
   void ApplicationModule::mainLoopWrapper() {
-    Application::getInstance().threadName() = "ApplicatioModule "+getName();
+    Application::registerThread("ApplicatioModule "+getName());
     Application::testableModeLock("start");
     // enter the main loop
     mainLoop();

src/Profiler.cc

+#include "Profiler.h"
+
+namespace ChimeraTK {
+  
+  std::list<Profiler::ThreadData*> Profiler::threadDataList;
+  
+  std::mutex Profiler::threadDataList_mutex;
+
+} /* namespace ChimeraTK */