From 7795ba60ff3c7973775f95cbfddeba796aa2743b Mon Sep 17 00:00:00 2001 From: Richard Harrison Date: Sun, 2 Sep 2018 13:47:55 +0200 Subject: [PATCH] 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 | 19 +++++++++++------ src/Time/TimeManager.hxx | 2 ++ src/Viewer/fg_os_osgviewer.cxx | 39 ++++++++++++++++++++++++++++++++-- 3 files changed, 52 insertions(+), 8 deletions(-) diff --git a/src/Time/TimeManager.cxx b/src/Time/TimeManager.cxx index f505e44c9..fd2fd8747 100644 --- a/src/Time/TimeManager.cxx +++ b/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 = fgGetDouble("/sim/frame-rate-throttle-hz", 0.0); + double throttle_hz = _maxFrameRate->getDoubleValue(); + + // 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 diff --git a/src/Time/TimeManager.hxx b/src/Time/TimeManager.hxx index 19bd9be20..eb771248b 100644 --- a/src/Time/TimeManager.hxx +++ b/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; diff --git a/src/Viewer/fg_os_osgviewer.cxx b/src/Viewer/fg_os_osgviewer.cxx index ae9409e68..625d7d42a 100644 --- a/src/Viewer/fg_os_osgviewer.cxx +++ b/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() ); }