X-Git-Url: https://git.mxchange.org/?a=blobdiff_plain;f=simgear%2Fstructure%2Fsubsystem_mgr.cxx;h=8109f41132b6397802308b60ac1b2c6ed54aa985;hb=ff7e70f4d570c472bbc6fe4198483d927914a35e;hp=8b1d5ea456309e1b99134f88ae43c73016bbe420;hpb=d22640ef4e938b523bdc30cd83370977d30de856;p=simgear.git

diff --git a/simgear/structure/subsystem_mgr.cxx b/simgear/structure/subsystem_mgr.cxx
index 8b1d5ea4..8109f411 100644
--- a/simgear/structure/subsystem_mgr.cxx
+++ b/simgear/structure/subsystem_mgr.cxx
@@ -1,5 +1,6 @@
 
 #include <simgear/debug/logstream.hxx>
+#include <simgear/timing/timestamp.hxx>
 
 #include "exception.hxx"
 #include "subsystem_mgr.hxx"
@@ -25,6 +26,11 @@ SGSubsystem::init ()
 {
 }
 
+void
+SGSubsystem::postinit ()
+{
+}
+
 void
 SGSubsystem::reinit ()
 {
@@ -65,6 +71,34 @@ SGSubsystem::is_suspended () const
 }
 
 
+void
+SGSubsystem::printTimingInformation ()
+{
+  SGTimeStamp startTime, endTime;
+   long duration;
+   for ( eventTimeVecIterator i = timingInfo.begin();
+          i != timingInfo.end();
+          i++) {
+       if (i == timingInfo.begin()) {
+           startTime = i->getTime();
+       } else {
+           endTime = i->getTime();
+           duration = (endTime - startTime);
+	   startTime = endTime;
+           SG_LOG(SG_GENERAL, SG_ALERT, "- Getting to timestamp :   " << i->getName() << " takes " << duration << " usec.");
+       }
+   }
+}
+
+
+
+void SGSubsystem::stamp(string name)
+{
+    SGTimeStamp now;
+    now.stamp();
+    timingInfo.push_back(TimingInfo(name, now));
+}
+
 
 ////////////////////////////////////////////////////////////////////////
 // Implementation of SGSubsystemGroup.
@@ -77,7 +111,10 @@ SGSubsystemGroup::SGSubsystemGroup ()
 SGSubsystemGroup::~SGSubsystemGroup ()
 {
     for (unsigned int i = 0; i < _members.size(); i++)
+    {
+        _members[i]->printTimingStatistics();
         delete _members[i];
+    }
 }
 
 void
@@ -87,6 +124,13 @@ SGSubsystemGroup::init ()
         _members[i]->subsystem->init();
 }
 
+void
+SGSubsystemGroup::postinit ()
+{
+    for (unsigned int i = 0; i < _members.size(); i++)
+        _members[i]->subsystem->postinit();
+}
+
 void
 SGSubsystemGroup::reinit ()
 {
@@ -112,7 +156,27 @@ void
 SGSubsystemGroup::update (double delta_time_sec)
 {
     for (unsigned int i = 0; i < _members.size(); i++)
-        _members[i]->update(delta_time_sec); // indirect call
+    {
+         SGTimeStamp start, now;
+         start.stamp();
+         _members[i]->update(delta_time_sec); // indirect call
+         now.stamp();
+         long b = ( now - start );
+         _members[i]->updateExecutionTime(b);
+         double threshold = _members[i]->getTimeWarningThreshold();
+         if (( b > threshold ) && (b > 10000)) {
+             _members[i]->printTimingInformation(b);
+         }
+    }
+}
+
+void 
+SGSubsystemGroup::collectDebugTiming(bool collect)
+{
+    for (unsigned int i = 0; i < _members.size(); i++)
+    {
+        _members[i]->collectDebugTiming(collect);
+    }
 }
 
 void
@@ -168,6 +232,26 @@ SGSubsystemGroup::remove_subsystem (const string &name)
     }
 }
 
+void
+SGSubsystemGroup::Member::printTimingStatistics ()
+{
+    if (collectTimeStats) {
+        double minTime = timeStat.min()   / 1000;
+        double maxTime = timeStat.max()   / 1000;
+        double meanTime = timeStat.mean() / 1000;
+        double stddev   = timeStat.stdDev()   / 1000;
+
+        char buffer[256];
+        snprintf(buffer, 256, "Timing summary for %20s.\n"
+                              "-  mean time: %04.2f ms.\n"
+                              "-  min time : %04.2f ms.\n"
+                              "-  max time : %04.2f ms.\n"
+                              "- stddev    : %04.2f ms.\n", name.c_str(), meanTime, minTime, maxTime, stddev);
+        SG_LOG(SG_GENERAL, SG_ALERT, buffer);
+    }
+}
+
+
 bool
 SGSubsystemGroup::has_subsystem (const string &name) const
 {
@@ -201,19 +285,19 @@ SGSubsystemGroup::Member::Member ()
     : name(""),
       subsystem(0),
       min_step_sec(0),
-      elapsed_sec(0)
+      elapsed_sec(0),
+      collectTimeStats(false)
 {
 }
 
+// This shouldn't be called due to subsystem pointer ownership issues.
 SGSubsystemGroup::Member::Member (const Member &)
 {
-    Member();
 }
 
 SGSubsystemGroup::Member::~Member ()
 {
-                                // FIXME: causes a crash
-//     delete subsystem;
+    delete subsystem;
 }
 
 void
@@ -229,6 +313,30 @@ SGSubsystemGroup::Member::update (double delta_time_sec)
 }
 
 
+void 
+SGSubsystemGroup::Member::printTimingInformation(double time)
+{
+     if (collectTimeStats) {
+         SG_LOG(SG_GENERAL, SG_ALERT, "Subsystem Timing Alert : " << time << " " << name);
+         subsystem->printTimingInformation();
+     }
+}
+
+double SGSubsystemGroup::Member::getTimeWarningThreshold()
+{
+    return (timeStat.mean() + 3 * timeStat.stdDev());
+}
+
+void SGSubsystemGroup::Member::updateExecutionTime(double time)
+{
+    if (collectTimeStats) {
+        timeStat += time;
+    }
+}
+
+
+
+
 
 ////////////////////////////////////////////////////////////////////////
 // Implementation of SGSubsystemMgr.
@@ -250,6 +358,13 @@ SGSubsystemMgr::init ()
             _groups[i].init();
 }
 
+void
+SGSubsystemMgr::postinit ()
+{
+    for (int i = 0; i < MAX_GROUPS; i++)
+            _groups[i].postinit();
+}
+
 void
 SGSubsystemMgr::reinit ()
 {
@@ -279,6 +394,14 @@ SGSubsystemMgr::update (double delta_time_sec)
     }
 }
 
+void 
+SGSubsystemMgr::collectDebugTiming(bool collect)
+{
+    for (int i = 0; i < MAX_GROUPS; i++) {
+        _groups[i].collectDebugTiming(collect);
+    }
+}
+
 void
 SGSubsystemMgr::suspend ()
 {