Move some code from the subsystem manager to a separate module.
Add module to evaluate performance and expose statistics to properties.
SGSmplstat.hxx
SGWeakPtr.hxx
SGWeakReferenced.hxx
+ SGPerfMon.hxx
Singleton.hxx
StringTable.hxx
callback.hxx
SGExpression.cxx
SGSmplhist.cxx
SGSmplstat.cxx
+ SGPerfMon.cxx
StringTable.cxx
commands.cxx
event_mgr.cxx
--- /dev/null
+// SGPerfMon.cxx -- Performance Monitoring
+//
+// Written by Thorsten Brehm, started November 2011.
+//
+// Copyright (C) 2011 Thorsten Brehm - brehmt (at) gmail com
+//
+// This program is free software; you can redistribute it and/or
+// modify it under the terms of the GNU General Public License as
+// published by the Free Software Foundation; either version 2 of the
+// License, or (at your option) any later version.
+//
+// This program is distributed in the hope that it will be useful, but
+// WITHOUT ANY WARRANTY; without even the implied warranty of
+// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
+// General Public License for more details.
+//
+// You should have received a copy of the GNU General Public License
+// along with this program; if not, write to the Free Software
+// Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
+//
+
+#ifdef HAVE_CONFIG_H
+# include <simgear_config.h>
+#endif
+
+#include "SGPerfMon.hxx"
+#include <simgear/structure/SGSmplstat.hxx>
+
+#include <stdio.h>
+#include <string.h>
+#include <string>
+
+#include <simgear/constants.h>
+#include <simgear/sg_inlines.h>
+#include <simgear/debug/logstream.hxx>
+#include <simgear/math/sg_geodesy.hxx>
+#include <simgear/sound/soundmgr_openal.hxx>
+#include <simgear/structure/exception.hxx>
+
+using std::string;
+
+SGPerformanceMonitor::SGPerformanceMonitor(SGSubsystemMgr* subSysMgr, SGPropertyNode_ptr root) :
+ _isEnabled(false),
+ _count(0)
+{
+ _root = root;
+ _subSysMgr = subSysMgr;
+}
+
+void
+SGPerformanceMonitor::bind(void)
+{
+ _statiticsSubsystems = _root->getChild("subsystems", 0, true);
+ _statisticsFlag = _root->getChild("enabled", 0, true);
+ _statisticsInterval = _root->getChild("interval-s", 0, true);
+// _statiticsMinJitter = _root->getChild("min-jitter-ms", 0, true);
+// _statiticsMinTime = _root->getChild("min-time-ms", 0, true);
+}
+
+void
+SGPerformanceMonitor::unbind(void)
+{
+ _statiticsSubsystems = 0;
+ _statisticsFlag = 0;
+ _statisticsInterval = 0;
+// _statiticsMinJitter = 0;
+// _statiticsMinTime = 0;
+}
+
+void
+SGPerformanceMonitor::init(void)
+{
+
+}
+
+void
+SGPerformanceMonitor::update(double dt)
+{
+ if (_isEnabled != _statisticsFlag->getBoolValue())
+ {
+ // flag has changed, update subsystem manager
+ _isEnabled = _statisticsFlag->getBoolValue();
+ if (_isEnabled)
+ _subSysMgr->setReportTimingCb(this,&subSystemMgrHook);
+ else
+ _subSysMgr->setReportTimingCb(this,0);
+ }
+
+ if (!_isEnabled)
+ return;
+
+ if (_lastUpdate.elapsedMSec() > 1000 * _statisticsInterval->getDoubleValue())
+ {
+ _count = 0;
+ // grab timing statistics
+ _subSysMgr->reportTiming();
+ _lastUpdate.stamp();
+ }
+}
+
+/** Callback hooked into the subsystem manager. */
+void
+SGPerformanceMonitor::subSystemMgrHook(void* userData, const std::string& name, SampleStatistic* timeStat)
+{
+ ((SGPerformanceMonitor*) userData)->reportTiming(name, timeStat);
+}
+
+/** Grabs and exposes timing information to properties */
+void
+SGPerformanceMonitor::reportTiming(const string& name, SampleStatistic* timeStat)
+{
+ SGPropertyNode* node = _statiticsSubsystems->getChild("subsystem",_count++,true);
+
+ double minMs = timeStat->min() / 1000;
+ double maxMs = timeStat->max() / 1000;
+ double meanMs = timeStat->mean() / 1000;
+ double stdDevMs = timeStat->stdDev() / 1000;
+ double totalMs = timeStat->total() / 1000;
+ int samples = timeStat->samples();
+
+ node->setStringValue("name", name);
+ node->setDoubleValue("min-ms", minMs);
+ node->setDoubleValue("max-ms", maxMs);
+ node->setDoubleValue("mean-ms", meanMs);
+ node->setDoubleValue("stddev-ms", stdDevMs);
+ node->setDoubleValue("total-ms", totalMs);
+ node->setDoubleValue("count",samples);
+
+ timeStat->reset();
+}
--- /dev/null
+// SGPerfMon.hxx -- Performance Tracing
+//
+// Written by Thorsten Brehm, started November 2011.
+//
+// Copyright (C) 2011 Thorsten Brehm - brehmt (at) gmail com
+//
+// This program is free software; you can redistribute it and/or
+// modify it under the terms of the GNU General Public License as
+// published by the Free Software Foundation; either version 2 of the
+// License, or (at your option) any later version.
+//
+// This program is distributed in the hope that it will be useful, but
+// WITHOUT ANY WARRANTY; without even the implied warranty of
+// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
+// General Public License for more details.
+//
+// You should have received a copy of the GNU General Public License
+// along with this program; if not, write to the Free Software
+// Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
+//
+
+#ifndef __SGPERFMON_HXX
+#define __SGPERFMON_HXX
+
+#include <simgear/props/props.hxx>
+#include <simgear/structure/subsystem_mgr.hxx>
+#include <simgear/timing/timestamp.hxx>
+
+class SampleStatistic;
+
+///////////////////////////////////////////////////////////////////////////////
+// SG Performance Monitor ////////////////////////////////////////////////////
+///////////////////////////////////////////////////////////////////////////////
+
+class SGPerformanceMonitor : public SGSubsystem
+{
+
+public:
+ SGPerformanceMonitor(SGSubsystemMgr* subSysMgr, SGPropertyNode_ptr root);
+
+ virtual void bind (void);
+ virtual void unbind (void);
+ virtual void init (void);
+ virtual void update (double dt);
+
+private:
+ static void subSystemMgrHook(void* userData, const std::string& name, SampleStatistic* timeStat);
+
+ void reportTiming(const std::string& name, SampleStatistic* timeStat);
+
+ SGTimeStamp _lastUpdate;
+ SGSubsystemMgr* _subSysMgr;
+ SGPropertyNode_ptr _root;
+ SGPropertyNode_ptr _statiticsSubsystems;
+ SGPropertyNode_ptr _statisticsFlag;
+ SGPropertyNode_ptr _statisticsInterval;
+// SGPropertyNode_ptr _statiticsMinJitter;
+// SGPropertyNode_ptr _statiticsMinTime;
+
+ bool _isEnabled;
+ int _count;
+};
+
+#endif // __SGPERFMON_HXX
{
n += 1;
x += value;
+ allTimeTotal += value;
x2 += (value * value);
if (minValue > value)
minValue = value;
double x;
double x2;
double minValue, maxValue;
+ double allTimeTotal;
public: SampleStatistic ();
inline virtual ~ SampleStatistic ();
double var () const;
double min () const;
double max () const;
+ double total () const;
double confidence (int p_percentage) const;
double confidence (double p_value) const;
inline SampleStatistic::SampleStatistic ()
{
+ allTimeTotal = 0;
reset ();
}
inline int SampleStatistic::samples () const
{
return (maxValue);
}
+inline double SampleStatistic::total () const
+{
+ return (allTimeTotal);
+}
inline SampleStatistic::~SampleStatistic ()
{
#include <simgear/math/SGMath.hxx>
#include "SGSmplstat.hxx"
-const int SG_MAX_SUBSYSTEM_EXCEPTIONS = 4;\f
+const int SG_MAX_SUBSYSTEM_EXCEPTIONS = 4;
+
////////////////////////////////////////////////////////////////////////
// Implementation of SGSubsystem
////////////////////////////////////////////////////////////////////////
+SGSubsystemTimingCb SGSubsystem::reportTimingCb = NULL;
+void* SGSubsystem::reportTimingUserData = NULL;
SGSubsystem::SGSubsystem ()
: _suspended(false)
return _suspended;
}
-
-void
-SGSubsystem::printTimingInformation ()
-{
- SGTimeStamp startTime;
- for ( eventTimeVecIterator i = timingInfo.begin();
- i != timingInfo.end();
- ++i) {
- if (i == timingInfo.begin()) {
- startTime = i->getTime();
- } else {
- SGTimeStamp endTime = i->getTime();
- SG_LOG(SG_GENERAL, SG_ALERT, "- Getting to timestamp : "
- << i->getName() << " takes " << endTime - startTime
- << " sec.");
- startTime = endTime;
- }
- }
-}
-
-
-
void SGSubsystem::stamp(const string& name)
{
timingInfo.push_back(TimingInfo(name, SGTimeStamp::now()));
virtual ~Member ();
virtual void update (double delta_time_sec);
- void printTimingInformation(double time);
- void printTimingStatistics(double minMaxTime=0.0,double minJitter=0.0);
- void updateExecutionTime(double time);
- double getTimeWarningThreshold();
- void collectDebugTiming (bool collect) { collectTimeStats = collect; };
-
+
+ void reportTiming(void) { if (reportTimingCb) reportTimingCb(reportTimingUserData, name, &timeStat); }
+ void updateExecutionTime(double time) { timeStat += time;}
+
SampleStatistic timeStat;
std::string name;
SGSubsystem * subsystem;
SGSubsystemGroup::~SGSubsystemGroup ()
{
- printTimingStatistics();
-
// reverse order to prevent order dependency problems
for (unsigned int i = _members.size(); i > 0; i--)
{
delta_time_sec = _fixedUpdateTime;
}
+ SGTimeStamp timeStamp;
while (loopCount-- > 0) {
for (unsigned int i = 0; i < _members.size(); i++)
{
- SGTimeStamp timeStamp = SGTimeStamp::now();
- _members[i]->update(delta_time_sec); // indirect call
- timeStamp = SGTimeStamp::now() - timeStamp;
- double b = timeStamp.toUSecs();
- _members[i]->updateExecutionTime(b);
- double threshold = _members[i]->getTimeWarningThreshold();
- if (( b > threshold ) && (b > 10000)) {
- _members[i]->printTimingInformation(b);
- }
+ bool recordTime = (reportTimingCb != NULL);
+ if (recordTime)
+ timeStamp = SGTimeStamp::now();
+
+ _members[i]->update(delta_time_sec); // indirect call
+
+ if ((recordTime)&&(reportTimingCb))
+ {
+ timeStamp = SGTimeStamp::now() - timeStamp;
+ _members[i]->updateExecutionTime(timeStamp.toUSecs());
+ }
}
} // of multiple update loop
}
-void
-SGSubsystemGroup::collectDebugTiming(bool collect)
-{
- for (unsigned int i = 0; i < _members.size(); i++)
- {
- _members[i]->collectDebugTiming(collect);
- }
-}
-
-void
-SGSubsystemGroup::printTimingStatistics(double minMaxTime,double minJitter)
+void
+SGSubsystemGroup::reportTiming(void)
{
for (unsigned int i = _members.size(); i > 0; i--)
{
- _members[i-1]->printTimingStatistics(minMaxTime, minJitter);
- _members[i-1]->timeStat.reset();
+ _members[i-1]->reportTiming();
}
}
_fixedUpdateTime = dt;
}
-/**
- * Print timing statistics.
- * Only show data if jitter exceeds minJitter or
- * maximum time exceeds minMaxTime.
- */
-void
-SGSubsystemGroup::Member::printTimingStatistics(double minMaxTime,double minJitter)
-{
- if (collectTimeStats) {
- double minTime = timeStat.min() / 1000;
- double maxTime = timeStat.max() / 1000;
- double meanTime = timeStat.mean() / 1000;
- double stddev = timeStat.stdDev() / 1000;
-
- if ((maxTime - minTime >= minJitter)||
- (maxTime >= minMaxTime))
- {
- 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
{
subsystem(0),
min_step_sec(0),
elapsed_sec(0),
- collectTimeStats(false),
exceptionCount(0)
{
}
}
-void
-SGSubsystemGroup::Member::printTimingInformation(double time)
-{
- if (collectTimeStats) {
- SG_LOG(SG_GENERAL, SG_ALERT, "Subsystem Timing Alert, subsystem \"" << name << "\": " << time/1000.0 << "ms");
- subsystem->printTimingInformation();
- }
-}
-
-double SGSubsystemGroup::Member::getTimeWarningThreshold()
-{
- return (timeStat.mean() + 3 * timeStat.stdDev());
-}
-
-void SGSubsystemGroup::Member::updateExecutionTime(double time)
-{
- if (collectTimeStats) {
- timeStat += time;
- }
-}
-
-
-
-
-\f
////////////////////////////////////////////////////////////////////////
// Implementation of SGSubsystemMgr.
////////////////////////////////////////////////////////////////////////
}
}
-void
-SGSubsystemMgr::collectDebugTiming(bool collect)
-{
- for (int i = 0; i < MAX_GROUPS; i++) {
- _groups[i]->collectDebugTiming(collect);
- }
-}
-
void
SGSubsystemMgr::suspend ()
{
return s->second;
}
+/** Trigger the timing callback to report data for all subsystems. */
void
-SGSubsystemMgr::printTimingStatistics(double minMaxTime,double minJitter)
+SGSubsystemMgr::reportTiming()
{
for (int i = 0; i < MAX_GROUPS; i++) {
- _groups[i]->printTimingStatistics(minMaxTime, minJitter);
+ _groups[i]->reportTiming();
} // of groups iteration
}
const SGTimeStamp& getTime() const { return time; }
};
+class SampleStatistic;
+
typedef std::vector<TimingInfo> eventTimeVec;
typedef std::vector<TimingInfo>::iterator eventTimeVecIterator;
+typedef void (*SGSubsystemTimingCb)(void* userData, const std::string& name, SampleStatistic* pStatistic);
\f
/**
/**
- * Suspend or resum operation of this subsystem.
+ * Suspend or resume operation of this subsystem.
*
* @param suspended true if the subsystem should be suspended, false
* otherwise.
*/
virtual bool is_suspended () const;
-
/**
- * Keep track of execution time.
- *
- * <p>This method keeps track of timing statistics for each subsystem.</p>
- *
- * @param time execution time in ms of last call.
+ * Trigger the callback to report timing information for all subsystems.
*/
- void updateExecutionTime(double time);
-
- /**
- * Print details of execution time.
- *
- * <p>For debugging purposes, developers can place stamp() calls
- * at strategic points in the update() function of each subsystem, which
- * record the time between the successive calls to stamp. This method,
- * printExecutionTime() is called after exectution of the subsystem
- * update function itself to conduct a post-hoc analysis of excecution
- * time</p>
- */
- void printTimingInformation();
+ void reportTiming(void);
/**
* Place time stamps at strategic points in the execution of subsystems
* update() member functions. Predominantly for debugging purposes.
*/
void stamp(const std::string& name);
-
-
protected:
bool _suspended;
eventTimeVec timingInfo;
- //int test;
+ static SGSubsystemTimingCb reportTimingCb;
+ static void* reportTimingUserData;
};
virtual void remove_subsystem (const std::string &name);
virtual bool has_subsystem (const std::string &name) const;
- void collectDebugTiming(bool collect);
- void printTimingStatistics(double minMaxTime=0.0,double minJitter=0.0);
+ void reportTiming(void);
/**
- *
+ *
*/
void set_fixed_update_time(double fixed_dt);
private:
virtual SGSubsystem * get_subsystem(const std::string &name) const;
- void collectDebugTiming(bool collect);
- void printTimingStatistics(double minMaxTime=0.0,double minJitter=0.0);
+ void reportTiming();
+ void setReportTimingCb(void* userData,SGSubsystemTimingCb cb) {reportTimingCb = cb;reportTimingUserData = userData;}
private:
SGSubsystemGroup* _groups[MAX_GROUPS];
-
+
typedef std::map<std::string, SGSubsystem*> SubsystemDict;
SubsystemDict _subsystem_map;
-
};
projects / simgear.git / commitdiff