* Added more debugging information to Threader/WorkerThread

* Added ability to enable/disable debugging
* Updated introspection tests

include/madara/threads/Threader.cpp

@@ -80,6 +80,9 @@ madara::threads::Threader::run (
 
     if (paused)
       thread->paused = 1;
+
+    if (debug_)
+      worker->debug_ = 1;
 
     (threads_[name] = std::move (worker))->run ();
   }
@@ -116,7 +119,9 @@ madara::threads::Threader::run (
 
     // if successful, run the thread
     if (new_thread)
+    {
       run (name, new_thread, paused);
+    }
   }
 }
 
@@ -150,6 +155,9 @@ madara::threads::Threader::run (double hertz,
     if (paused)
       thread->paused = 1;
 
+    if (debug_)
+      worker->debug_ = 1;
+
     (threads_[name] = std::move (worker))->run ();
   }
   else if (thread != 0 && name == "")

include/madara/threads/Threader.h

@@ -197,6 +197,38 @@ namespace madara
       **/
       void terminate (const std::string name);
 
+      /**
+      * Requests a specific thread to disable debug mode. Debug mode
+      * prints thread performance information such as durations
+      * and executions.
+      * @param name    unique thread name for the thread.
+      **/
+      void disable_debug (const std::string name);
+
+      /**
+      * Requests that all new threads disable debug mode. Debug mode
+      * prints thread performance information such as durations
+      * and executions. Disabled is the default mode.
+      * @param name    unique thread name for the thread.
+      **/
+      void disable_debug (void);
+
+      /**
+      * Requests a specific thread to enter debug mode. Debug mode
+      * prints thread performance information such as durations
+      * and executions.
+      * @param name    unique thread name for the thread.
+      **/
+      void enable_debug (const std::string name);
+
+      /**
+      * Requests that all new threads to enter debug mode. Debug mode
+      * prints thread performance information such as durations
+      * and executions. Disabled is the default mode.
+      * @param name    unique thread name for the thread.
+      **/
+      void enable_debug (void);
+
       /**
       * Requests all threads to terminate
       **/
@@ -237,6 +269,11 @@ namespace madara
        * the threads that are still active
        **/
       NamedWorkerThreads threads_;
+
+      /**
+       * indicates if threads should be started in debug mode
+       **/
+      bool debug_;
     };
   }
 }

include/madara/threads/Threader.inl

@@ -19,16 +19,36 @@ madara::threads::Threader::change_hertz (const std::string name, double hertz)
   control_.set (name + ".hertz", hertz);
 }
 
+inline void
+madara::threads::Threader::enable_debug (const std::string name)
+{
+  control_.set (name + ".debug", true);
+}
+
+inline void
+madara::threads::Threader::disable_debug (const std::string name)
+{
+  control_.set (name + ".debug", false);
+}
+
+inline void
+madara::threads::Threader::enable_debug (void)
+{
+  debug_ = true;
+}
+
+inline void
+madara::threads::Threader::disable_debug (void)
+{
+  debug_ = false;
+}
+
 inline madara::knowledge::KnowledgeBase
 madara::threads::Threader::get_data_plane (void)
 {
   return data_;
 }
 
-/**
-* Gets the control plane used by threads
-* @return  the knowledge base used by threader for control of threads
-**/
 inline madara::knowledge::KnowledgeBase
 madara::threads::Threader::get_control_plane (void)
 {

include/madara/threads/WorkerThread.cpp

@@ -47,6 +47,16 @@ WorkerThread::WorkerThread (
     end_time_.set_name (
       base_string.str () + ".end_time", control);
 
+    last_duration_.set_name (
+      base_string.str () + ".last_duration", control);
+    min_duration_.set_name (
+      base_string.str () + ".min_duration", control);
+    max_duration_.set_name (
+      base_string.str () + ".max_duration", control);
+
+    debug_.set_name (
+      base_string.str () + ".debug", control);
+
     finished_ = 0;
     started_ = 0;
     new_hertz_ = hertz_;
@@ -138,9 +148,18 @@ WorkerThread::svc (void)
       utility::TimeValue next_epoch;
       utility::Duration frequency;
 
+      // only allow one-way communication of durations. We never read control
+      int64_t min_duration = -1;
+      int64_t max_duration = 0;
+      int64_t last_duration = 0;
+      bool max_duration_changed = true;
+      bool min_duration_changed = true;
+
       bool one_shot = true;
       bool blaster = false;
 
+      bool debug = debug_.is_true ();
+
       knowledge::VariableReference terminated;
       knowledge::VariableReference paused;
 
@@ -157,7 +176,10 @@ WorkerThread::svc (void)
       madara::logger::Logger::set_thread_hertz(hertz_);
 #endif
 
-      start_time_ = utility::get_time ();
+      if (debug)
+      {
+        start_time_ = utility::get_time ();
+      }
 
       while (control_.get (terminated).is_false ())
       {
@@ -173,13 +195,53 @@ WorkerThread::svc (void)
 
           try
           {
-            last_start_time_ = utility::get_time ();
-            ++executions_;
+            int64_t start_time = 0, end_time = 0;
+            debug = debug_.is_true ();
+
+            if (debug)
+            {
+              start_time = utility::get_time ();
+              ++executions_;
+            }
 
             thread_->run ();
 
-            end_time_ = utility::get_time ();
-          }
+            if (debug)
+            {
+              end_time = utility::get_time ();
+
+              // update duration information
+              last_duration = end_time - start_time;
+              if (min_duration == -1 || last_duration < min_duration)
+              {
+                min_duration = last_duration;
+                min_duration_changed = true;
+              }
+              if (last_duration > max_duration)
+              {
+                max_duration = last_duration;
+                max_duration_changed = true;
+              }
+
+              // lock control plane and update
+              {
+                // write updates to control
+                knowledge::ContextGuard guard (control_);
+                last_start_time_ = start_time;
+                end_time_ = end_time;
+
+                last_duration_ = last_duration;
+                if (max_duration_changed)
+                {
+                  max_duration_ = max_duration;
+                }
+                if (min_duration_changed)
+                {
+                  min_duration_ = min_duration;
+                }
+              } // end lock of control plane
+            } // end if debug
+          } // end try of the run
           catch (const std::exception &e)
           {
             madara_logger_ptr_log (logger::global_logger.get(), logger::LOG_EMERGENCY,

include/madara/threads/WorkerThread.h

@@ -168,6 +168,26 @@ namespace madara
        **/
       knowledge::containers::Integer end_time_;
 
+      /**
+       * duration of last run
+       **/
+      knowledge::containers::Integer last_duration_;
+
+      /**
+       * minimum duration of all runs
+       **/
+      knowledge::containers::Integer min_duration_;
+
+      /**
+       * maximum duration of all runs
+       **/
+      knowledge::containers::Integer max_duration_;
+
+      /**
+       * flag for whether or not to save debug information in control
+       **/
+      knowledge::containers::Integer debug_;
+
       /**
        * hertz rate for worker thread executions
        **/

tests/threads/test_threader_introspection.cpp

@@ -192,6 +192,8 @@ int main (int argc, char ** argv)
   // create a threader for running threads
   threads::Threader threader (knowledge);
 
+  threader.enable_debug ();
+
   utility::Timer <utility::Clock> timer;
   timer.start ();
 
@@ -253,5 +255,22 @@ int main (int argc, char ** argv)
 
   threader.wait ();
 
+  madara_logger_ptr_log (logger::global_logger.get(), logger::LOG_ALWAYS,
+    "Starting new thread without debugging and running for 5s\n",
+    timer.duration_s ());
+
+  threader.disable_debug ();
+  threader.run (hertz, "no_debug", new EmptyThread (), true);
+
+  // sleep for 5 seconds before printing and stopping
+  utility::sleep (5.0);
+
+  // print the aggregate counter to the screen
+  control.print ();
+
+  threader.terminate ();
+
+  threader.wait ();
+
   return 0;
 }