
- Matt
Code: Select all
class TimerDiagnostics
{
public:
TimerDiagnostics();
unsigned long m_msStartTime;
unsigned long m_msElapsed;
unsigned long m_msHitchTime;
unsigned long m_msHitchLength;
};
class DiagnosticsSystem
{
// ... <snip> ...
public:
// This is used to gather stats on how long per-tick operations take,
// like physics or graphics.
// You can use this to measure anything, as long as you make sure to call
// StartTime and StopTime together in pairs.
void StartTimer( const String& i_strID );
void StopTimer( const String& i_strID );
void SetDisplayTimerDiagnostics( bool i_bDisplay );
String FormatTimerDiagnostics() const;
private:
std::map< String, TimerDiagnostics > m_mapTimerDiagnostics;
bool m_bDisplayTimerDiagnostics;
Code: Select all
void DiagnosticsSystem::StartTimer( const String& i_strID )
{
// Don't bother unless we've enabled timer diagnostics.
if ( !m_bDisplayTimerDiagnostics )
{
return;
}
std::map< String, TimerDiagnostics >::iterator it = m_mapTimerDiagnostics.find( i_strID );
if ( it == m_mapTimerDiagnostics.end() )
{
TimerDiagnostics diag;
// The following GetTimer function returns an Ogre::Timer
diag.m_msStartTime = TimeSys()->GetTimer().getMillisecondsCPU();
m_mapTimerDiagnostics[ i_strID ] = diag;
}
else
{
TimerDiagnostics& diag = it->second;
diag.m_msStartTime = TimeSys()->GetTimer().getMillisecondsCPU();
}
}
void DiagnosticsSystem::StopTimer( const String& i_strID )
{
// Don't bother unless we've enabled timer diagnostics.
if ( !m_bDisplayTimerDiagnostics )
{
return;
}
std::map< String, TimerDiagnostics >::iterator it = m_mapTimerDiagnostics.find( i_strID );
if ( it == m_mapTimerDiagnostics.end() )
{
// This could happen if we've enabled timer diagnostics in between a StartTimer and
// StopTimer call. We'll just ignore this StopTimer call, and things will work out
// next frame.
return;
}
unsigned long msNow = TimeSys()->GetTimer().getMillisecondsCPU();
// Calculate the elapsed time
TimerDiagnostics& diag = it->second;
diag.m_msElapsed = msNow - diag.m_msStartTime;
// Clear out any old hitch times.
const unsigned long msHitchClear = 2000; // clear hitches after 2 seconds
if ( msNow > diag.m_msHitchTime + msHitchClear )
{
diag.m_msHitchTime = 0;
diag.m_msHitchLength = 0;
}
// Is this the longest hitch?
if ( diag.m_msElapsed > diag.m_msHitchLength )
{
diag.m_msHitchLength = diag.m_msElapsed;
diag.m_msHitchTime = msNow;
}
}
void DiagnosticsSystem::SetDisplayTimerDiagnostics( bool i_bDisplay )
{
m_bDisplayTimerDiagnostics = i_bDisplay;
}
String DiagnosticsSystem::FormatTimerDiagnostics() const
{
std::stringstream ssTimer;
ssTimer << "Timer Diagnostics" << std::endl;
std::map< String, TimerDiagnostics >::const_iterator it = m_mapTimerDiagnostics.begin();
for ( ; it != m_mapTimerDiagnostics.end(); ++it )
{
const String& strID = it->first;
const TimerDiagnostics& diag = it->second;
// Skip anything that is 0 ms
if ( diag.m_msElapsed == 0 && diag.m_msHitchLength == 0 ) continue;
ssTimer << std::setw(12) << strID << ": t=" << std::setw(3) << diag.m_msElapsed << " h=" << std::setw(3) << diag.m_msHitchLength << std::endl;
}
Viewport* pViewport = CameraSys()->GetViewport();
if ( pViewport && pViewport->getTarget() )
{
ssTimer << "Batch Count: " << pViewport->getTarget()->getBatchCount() << std::endl;
}
return ssTimer.str();
}
Code: Select all
// ...
static String strTimerID( "Graphics" );
DiagnosticsSys()->StartTimer( strTimerID );
m_pOgreRoot->renderOneFrame();
DiagnosticsSys()->StopTimer( strTimerID );
// ...
During the code inspection, a couple of minor points were noticed: -
Function inlining was critical to performance.
For MSVC, at least, a "delete 0" caused execution of 11 assembly instructions, including a function call. So in cases where performance is at an absolute premium it can be worth inserting the extra manual test.
Code: Select all
PROFILE_FUNC();
Code: Select all
#define OGRE_PROFILING 1
Code: Select all
void someFunction()
{
OgreProfile( "someFunction()" );
... // some code
if( condition )
{
OgreProfile( "someFunction(): branch 1" );
... // more code
}
}