Added time statistics for the simulation host.

These are the time statistics that are the simulation code, which is basically everything except the rendering.

For a while I've wondered how efficient each of my JSBSim models are, and how much of our valuable frame time is spent on simulation modules.

Ideally the simulation modules should be taking 2-3ms, anything longer indicates a need to consider optimising things more.

These are the new properties that are added by this change:

/sim/rendering/sim-frame-count        Number of frames since start (or last time
/sim/rendering/sim-frame-count-reset  Reset statistics. Can be useful to reset monitoring after a slow startup
/sim/rendering/sim-host-avg-ms        Average amount of time spent in the "simulation" rather than rendering. This attempts to take into consideration the
                                      frame rate throttling but when throttled this figure is less reliable.
/sim/rendering/sim-host-total-ms      Total milliseconds since reset
/sim/time/frame-wait-ms               Current frame wait to meet throttling rate.

src/Time/TimeManager.cxx

@@ -83,7 +83,8 @@ void TimeManager::init()
   _timeOverride = fgGetNode("/sim/time/cur-time-override", true);
   _warp = fgGetNode("/sim/time/warp", true);
   _warp->addChangeListener(this);
-  
+  _maxFrameRate  = fgGetNode("/sim/frame-rate-throttle-hz", true);
+
   _warpDelta = fgGetNode("/sim/time/warp-delta", true);
   
   SGPath zone(globals->get_fg_root());
@@ -114,7 +115,7 @@ void TimeManager::init()
     _timeDelta = fgGetNode("sim/time/delta-realtime-sec", true);
     _simTimeDelta = fgGetNode("sim/time/delta-sec", true);
     _mpClockNode = fgGetNode("sim/time/mp-clock-sec", true);
-
+    _frameWait = fgGetNode("sim/time/frame-wait-ms", true);
     _simTimeFactor = fgGetNode("/sim/speed-up", true);
     // use pre-set value but ensure we get a sane default
     if (!_simTimeDelta->hasValue()) {
@@ -343,13 +344,19 @@ void TimeManager::computeFrameRate()
 
 void TimeManager::throttleUpdateRate()
 {
-  // common case, no throttle requested
+  double throttle_hz = _maxFrameRate->getDoubleValue();
-  double throttle_hz = fgGetDouble("/sim/frame-rate-throttle-hz", 0.0);
+
+  // no delay required.
   if (throttle_hz <= 0)
-    return; // no-op
+  {
+      _frameWait->setDoubleValue(0);
+      return;
+  }
+  SGTimeStamp frameWaitStart = SGTimeStamp::now();
 
   // sleep for exactly 1/hz seconds relative to the past valid timestamp
-  SGTimeStamp::sleepUntil(_lastStamp + SGTimeStamp::fromSec(1/throttle_hz));
+  SGTimeStamp::sleepUntil(_lastStamp + SGTimeStamp::fromSec(1 / throttle_hz));
+  _frameWait->setDoubleValue(frameWaitStart.elapsedMSec());
 }
 
 // periodic time updater wrapper

src/Time/TimeManager.hxx

@@ -81,6 +81,8 @@ private:
   SGPropertyNode_ptr _warpDelta;
   SGPropertyNode_ptr _simTimeFactor;
   SGPropertyNode_ptr _mpClockNode;
+  SGPropertyNode_ptr _frameWait;
+  SGPropertyNode_ptr _maxFrameRate;
 
   bool _lastClockFreeze;
   bool _adjustWarpOnUnfreeze;

src/Viewer/fg_os_osgviewer.cxx

@@ -247,10 +247,16 @@ void fgOSOpenWindow(bool stencil)
     viewer->setSceneData(new osg::Group);
     globals->get_renderer()->setViewer(viewer.get());
 }
-
+SGPropertyNode* simHost = 0, *simFrameCount, *simTotalHostTime, *simFrameResetCount, *frameWait;
 void fgOSResetProperties()
 {
     SGPropertyNode* osgLevel = fgGetNode("/sim/rendering/osg-notify-level", true);
+    simTotalHostTime = fgGetNode("/sim/rendering/sim-host-total-ms", true);
+    simHost = fgGetNode("/sim/rendering/sim-host-avg-ms", true);
+    simFrameCount = fgGetNode("/sim/rendering/sim-frame-count", true);
+    simFrameResetCount = fgGetNode("/sim/rendering/sim-frame-count-reset", true);
+    frameWait = fgGetNode("/sim/time/frame-wait-ms", true);
+    simFrameResetCount->setBoolValue(false);
     NotifyLevelListener* l = new NotifyLevelListener;
     globals->addListenerToCleanup(l);
     osgLevel->addChangeListener(l, true);
@@ -287,6 +293,7 @@ void fgOSExit(int code)
     // sglog static, despite our best efforts in boostrap.cxx
     osg::setNotifyHandler(new osg::StandardNotifyHandler);
 }
+SGTimeStamp _lastUpdate;
 
 int fgOSMainLoop()
 {
@@ -298,8 +305,36 @@ int fgOSMainLoop()
     while (!viewer->done()) {
         fgIdleHandler idleFunc = globals->get_renderer()->getEventHandler()->getIdleHandler();
         if (idleFunc)
+        {
+            _lastUpdate.stamp();
             (*idleFunc)();
-
+            if (fgGetBool("/sim/position-finalized", false))
+            {
+                if (simHost && simFrameCount && simTotalHostTime && simFrameResetCount)
+                {
+                    int curFrameCount = simFrameCount->getIntValue();
+                    double totalSimTime = simTotalHostTime->getDoubleValue();
+                    if (simFrameResetCount->getBoolValue())
+                    {
+                        curFrameCount = 0;
+                        totalSimTime = 0;
+                        simFrameResetCount->setBoolValue(false);
+                    }
+                    double lastSimFrame_ms = _lastUpdate.elapsedMSec();
+                    double idle_wait = 0;
+                    if (frameWait)
+                        idle_wait = frameWait->getDoubleValue();
+                    if (lastSimFrame_ms > 0)
+                    {
+                        totalSimTime += lastSimFrame_ms - idle_wait;
+                        simTotalHostTime->setDoubleValue(totalSimTime);
+                        curFrameCount++;
+                        simFrameCount->setIntValue(curFrameCount);
+                        simHost->setDoubleValue(totalSimTime / curFrameCount);
+                    }
+                }
+            }
+        }
         globals->get_renderer()->update();
         viewer->frame( globals->get_sim_time_sec() );
     }