Browse Source

Template-ize hsTimer return values.

Darryl Pogue 11 years ago
parent
commit
a3ae4201a2
  1. 2
      Sources/Plasma/FeatureLib/pfConsole/pfConsole.cpp
  2. 4
      Sources/Plasma/FeatureLib/pfConsole/pfDispatchLog.cpp
  3. 63
      Sources/Plasma/NucleusLib/inc/hsTimer.h
  4. 8
      Sources/Plasma/NucleusLib/inc/plProfile.h
  5. 20
      Sources/Plasma/NucleusLib/inc/plProfileManager.cpp
  6. 10
      Sources/Plasma/NucleusLib/inc/plProfileManager.h
  7. 10
      Sources/Plasma/NucleusLib/pnDispatch/plDispatch.cpp
  8. 42
      Sources/Plasma/NucleusLib/pnTimer/hsTimer.cpp
  9. 2
      Sources/Plasma/PubUtilLib/plPipeline/plDTProgressMgr.cpp
  10. 14
      Sources/Plasma/PubUtilLib/plResMgr/plResManager.cpp
  11. 6
      Sources/Plasma/PubUtilLib/plStatGather/plAutoProfile.cpp

2
Sources/Plasma/FeatureLib/pfConsole/pfConsole.cpp

@ -1025,7 +1025,7 @@ void pfConsole::Draw( plPipeline *p )
plDebugText& drawText = plDebugText::Instance(); plDebugText& drawText = plDebugText::Instance();
thisTime = (float)hsTimer::PrecTicksToSecs( hsTimer::GetPrecTickCount() ); thisTime = hsTimer::GetSeconds<float>();
if( fMode == kModeHidden && fEffectCounter == 0 ) if( fMode == kModeHidden && fEffectCounter == 0 )
{ {

4
Sources/Plasma/FeatureLib/pfConsole/pfDispatchLog.cpp

@ -52,7 +52,7 @@ static bool DumpSpecificMsgInfo(plMessage* msg, plString& info);
plDispatchLog::plDispatchLog() : plDispatchLog::plDispatchLog() :
fLog(nil), fLog(nil),
fStartTicks(hsTimer::GetFullTickCount()) fStartTicks(hsTimer::GetTicks())
{ {
fLog = plStatusLogMgr::GetInstance().CreateStatusLog(20, "Dispatch.log", plStatusLog::kAlignToTop | plStatusLog::kFilledBackground | plStatusLog::kRawTimeStamp); fLog = plStatusLogMgr::GetInstance().CreateStatusLog(20, "Dispatch.log", plStatusLog::kAlignToTop | plStatusLog::kFilledBackground | plStatusLog::kRawTimeStamp);
fIncludeTypes.SetSize(plFactory::GetNumClasses()); fIncludeTypes.SetSize(plFactory::GetNumClasses());
@ -130,7 +130,7 @@ void plDispatchLog::DumpMsg(plMessage* msg, int numReceivers, int sendTimeMs, in
fLog->AddLine("\n"); fLog->AddLine("\n");
} }
float sendTime = hsTimer::FullTicksToMs(hsTimer::GetFullTickCount() - fStartTicks); float sendTime = hsTimer::GetMilliSeconds<float>(hsTimer::GetTicks() - fStartTicks);
char indentStr[50]; char indentStr[50];
indent = hsMinimum(indent, sizeof(indentStr)-1); indent = hsMinimum(indent, sizeof(indentStr)-1);

63
Sources/Plasma/NucleusLib/inc/hsTimer.h

@ -46,6 +46,7 @@ You can contact Cyan Worlds, Inc. by email legal@cyan.com
class plTimerShare class plTimerShare
{ {
private:
typedef std::chrono::high_resolution_clock Clock; typedef std::chrono::high_resolution_clock Clock;
typedef std::chrono::time_point<Clock> TimePoint; typedef std::chrono::time_point<Clock> TimePoint;
typedef Clock::duration Duration; typedef Clock::duration Duration;
@ -72,8 +73,39 @@ protected:
bool fClamping; bool fClamping;
double GetSeconds() const; template<typename T = double>
double GetMilliSeconds() const; T GetSeconds() const
{
typedef std::chrono::duration<T> duration_type;
Duration d = GetRawTicks();
return std::chrono::duration_cast<duration_type>(d).count();
}
template<typename T = double>
T GetSeconds(uint64_t ticks) const
{
typedef std::chrono::duration<T> duration_type;
Duration d(ticks);
return std::chrono::duration_cast<duration_type>(d).count();
}
template<typename T = double>
T GetMilliSeconds() const
{
typedef std::chrono::duration<T, std::milli> duration_type;
Duration d = GetRawTicks();
return std::chrono::duration_cast<duration_type>(d).count();
}
template<typename T = double>
T GetMilliSeconds(uint64_t ticks) const
{
typedef std::chrono::duration<T, std::milli> duration_type;
Duration d(ticks);
return std::chrono::duration_cast<duration_type>(d).count();
}
uint64_t GetTicks() const;
float GetDelSysSeconds() const { return fDelSysSeconds; } float GetDelSysSeconds() const { return fDelSysSeconds; }
double GetSysSeconds() const { return fSysSeconds; } double GetSysSeconds() const { return fSysSeconds; }
@ -112,8 +144,19 @@ protected:
public: public:
static double GetSeconds() { return fTimer->GetSeconds(); } template<typename T = double>
static double GetMilliSeconds() { return fTimer->GetMilliSeconds(); } static T GetSeconds() { return fTimer->GetSeconds<T>(); }
template<typename T = double>
static T GetSeconds(uint64_t ticks) { return fTimer->GetSeconds<T>(ticks); }
template<typename T = double>
static T GetMilliSeconds() { return fTimer->GetMilliSeconds<T>(); }
template<typename T = double>
static T GetMilliSeconds(uint64_t ticks) { return fTimer->GetMilliSeconds<T>(ticks); }
static uint64_t GetTicks() { return fTimer->GetTicks(); }
static float GetDelSysSeconds() { return fTimer->GetDelSysSeconds(); } static float GetDelSysSeconds() { return fTimer->GetDelSysSeconds(); }
static double GetSysSeconds() { return fTimer->GetSysSeconds(); } static double GetSysSeconds() { return fTimer->GetSysSeconds(); }
@ -133,18 +176,6 @@ public:
static float GetTimeClamp() { return fTimer->GetTimeClamp(); } static float GetTimeClamp() { return fTimer->GetTimeClamp(); }
static bool IsClamping() { return fTimer->IsClamping(); } static bool IsClamping() { return fTimer->IsClamping(); }
///////////////////////////
// Precision timer routines - these are stateless and implemented as statics.
///////////////////////////
static uint32_t GetPrecTickCount();
static double GetPrecTicksPerSec();
static double PrecTicksToSecs(uint32_t ticks);
// If you need to time something longer than 20 seconds, use this instead of
// the precision timer. It works the same, it just gives you full resolution.
static uint64_t GetFullTickCount();
static float FullTicksToMs(uint64_t ticks);
// //
// Pass GetTheTimer() into other process space, and then call SetTheTimer() on it. // Pass GetTheTimer() into other process space, and then call SetTheTimer() on it.
static void SetTheTimer(plTimerShare* timer); static void SetTheTimer(plTimerShare* timer);

8
Sources/Plasma/NucleusLib/inc/plProfile.h

@ -153,7 +153,7 @@ public:
protected: protected:
const char* fName; // Name of timer const char* fName; // Name of timer
uint32_t fValue; uint64_t fValue;
uint32_t fAvgCount; uint32_t fAvgCount;
uint64_t fAvgTotal; uint64_t fAvgTotal;
@ -168,7 +168,7 @@ protected:
void IAddAvg(); void IAddAvg();
void IPrintValue(uint32_t value, char* buf, bool printType); void IPrintValue(uint64_t value, char* buf, bool printType);
public: public:
plProfileBase(); plProfileBase();
@ -179,7 +179,7 @@ public:
void UpdateAvg(); void UpdateAvg();
uint32_t GetValue(); uint64_t GetValue();
void PrintValue(char* buf, bool printType=true); void PrintValue(char* buf, bool printType=true);
void PrintAvg(char* buf, bool printType=true); void PrintAvg(char* buf, bool printType=true);
@ -230,7 +230,7 @@ public:
void Inc(int i = 1) { fValue += i;} void Inc(int i = 1) { fValue += i;}
void Dec(int i = 1) { fValue -= i;} void Dec(int i = 1) { fValue -= i;}
void Set(uint32_t value) { fValue = value; } void Set(uint64_t value) { fValue = value; }
// //
// For multiple timings per frame of the same thing ie. Each particle system // For multiple timings per frame of the same thing ie. Each particle system

20
Sources/Plasma/NucleusLib/inc/plProfileManager.cpp

@ -150,15 +150,15 @@ uint32_t GetProcSpeedAlt()
} }
#define GetProfileTicks() GetPentiumCounter() #define GetProfileTicks() GetPentiumCounter()
#define TicksToMSec(t) (float(t) / float(gCyclesPerMS))
#else #else
#define GetProfileTicks() hsTimer::GetPrecTickCount() #define GetProfileTicks() hsTimer::GetTicks()
#define TicksToMSec(t) hsTimer::GetMilliSeconds<float>(t)
#endif // USE_FAST_TIMER #endif // USE_FAST_TIMER
#define TicksToMSec(t) (float(t) / float(gCyclesPerMS))
#define MSecToTicks(t) (float(t) * float(gCyclesPerMS))
plProfileManager::plProfileManager() : fLastAvgTime(0), fProcessorSpeed(0) plProfileManager::plProfileManager() : fLastAvgTime(0), fProcessorSpeed(0)
{ {
@ -169,8 +169,6 @@ plProfileManager::plProfileManager() : fLastAvgTime(0), fProcessorSpeed(0)
fProcessorSpeed = GetProcSpeedAlt(); fProcessorSpeed = GetProcSpeedAlt();
gCyclesPerMS = fProcessorSpeed / 1000; gCyclesPerMS = fProcessorSpeed / 1000;
#else
gCyclesPerMS = hsTimer::GetPrecTicksPerSec() / 1000;
#endif #endif
} }
@ -251,7 +249,7 @@ void plProfileManager::EndFrame()
} }
} }
uint32_t plProfileManager::GetTime() uint64_t plProfileManager::GetTime()
{ {
return GetProfileTicks(); return GetProfileTicks();
} }
@ -300,10 +298,10 @@ void plProfileBase::UpdateAvg()
} }
} }
uint32_t plProfileBase::GetValue() uint64_t plProfileBase::GetValue()
{ {
if (hsCheckBits(fDisplayFlags, kDisplayTime)) if (hsCheckBits(fDisplayFlags, kDisplayTime))
return (uint32_t)TicksToMSec(fValue); return (uint64_t)TicksToMSec(fValue);
else else
return fValue; return fValue;
} }
@ -334,7 +332,7 @@ static const char *insertCommas(unsigned int value)
return str; return str;
} }
void plProfileBase::IPrintValue(uint32_t value, char* buf, bool printType) void plProfileBase::IPrintValue(uint64_t value, char* buf, bool printType)
{ {
if (hsCheckBits(fDisplayFlags, kDisplayCount)) if (hsCheckBits(fDisplayFlags, kDisplayCount))
{ {
@ -416,7 +414,7 @@ plProfileLaps::LapInfo* plProfileLaps::IFindLap(const char* lapName)
return nil; return nil;
} }
void plProfileLaps::BeginLap(uint32_t curValue, const char* name) void plProfileLaps::BeginLap(uint64_t curValue, const char* name)
{ {
LapInfo* lap = IFindLap(name); LapInfo* lap = IFindLap(name);
if (!lap) if (!lap)
@ -432,7 +430,7 @@ void plProfileLaps::BeginLap(uint32_t curValue, const char* name)
lap->BeginTiming(curValue); lap->BeginTiming(curValue);
} }
void plProfileLaps::EndLap(uint32_t curValue, const char* name) void plProfileLaps::EndLap(uint64_t curValue, const char* name)
{ {
LapInfo* lap = IFindLap(name); LapInfo* lap = IFindLap(name);

10
Sources/Plasma/NucleusLib/inc/plProfileManager.h

@ -76,7 +76,7 @@ public:
uint32_t GetProcessorSpeed() { return fProcessorSpeed; } uint32_t GetProcessorSpeed() { return fProcessorSpeed; }
// Backdoor for hack timers in calculated profiles // Backdoor for hack timers in calculated profiles
static uint32_t GetTime(); static uint64_t GetTime();
}; };
class plProfileLaps class plProfileLaps
@ -91,16 +91,16 @@ protected:
LapInfo(const char* name) { fName = name; fDisplayFlags = kDisplayTime; } LapInfo(const char* name) { fName = name; fDisplayFlags = kDisplayTime; }
bool operator<(const LapInfo& rhs) const { return fLastAvg < rhs.fLastAvg; } bool operator<(const LapInfo& rhs) const { return fLastAvg < rhs.fLastAvg; }
void BeginTiming(uint32_t value) { fValue -= value; } void BeginTiming(uint64_t value) { fValue -= value; }
void EndTiming(uint32_t value) { fValue += value; fTimerSamples++; } void EndTiming(uint64_t value) { fValue += value; fTimerSamples++; }
}; };
std::vector<LapInfo> fLapTimes; std::vector<LapInfo> fLapTimes;
LapInfo* IFindLap(const char* lapName); LapInfo* IFindLap(const char* lapName);
public: public:
void BeginLap(uint32_t curValue, const char* name); void BeginLap(uint64_t curValue, const char* name);
void EndLap(uint32_t curValue, const char* name); void EndLap(uint64_t curValue, const char* name);
void BeginFrame(); void BeginFrame();
void EndFrame(); void EndFrame();

10
Sources/Plasma/NucleusLib/pnDispatch/plDispatch.cpp

@ -311,7 +311,7 @@ void plDispatch::IMsgDispatch()
static uint64_t startTicks = 0; static uint64_t startTicks = 0;
if (plDispatchLogBase::IsLogging()) if (plDispatchLogBase::IsLogging())
startTicks = hsTimer::GetFullTickCount(); startTicks = hsTimer::GetTicks();
int i, numReceivers=0; int i, numReceivers=0;
for( i = 0; fMsgCurrent && i < fMsgCurrent->GetNumReceivers(); i++ ) for( i = 0; fMsgCurrent && i < fMsgCurrent->GetNumReceivers(); i++ )
@ -343,7 +343,7 @@ void plDispatch::IMsgDispatch()
} }
#ifndef PLASMA_EXTERNAL_RELEASE #ifndef PLASMA_EXTERNAL_RELEASE
uint32_t rcvTicks = hsTimer::GetPrecTickCount(); uint64_t rcvTicks = hsTimer::GetTicks();
// Object could be deleted by this message, so we need to log this stuff now // Object could be deleted by this message, so we need to log this stuff now
plString keyname = "(unknown)"; plString keyname = "(unknown)";
@ -373,9 +373,9 @@ void plDispatch::IMsgDispatch()
#ifndef PLASMA_EXTERNAL_RELEASE #ifndef PLASMA_EXTERNAL_RELEASE
if (plDispatchLogBase::IsLoggingLong()) if (plDispatchLogBase::IsLoggingLong())
{ {
rcvTicks = hsTimer::GetPrecTickCount() - rcvTicks; rcvTicks = hsTimer::GetTicks() - rcvTicks;
float rcvTime = (float)(hsTimer::PrecTicksToSecs(rcvTicks) * 1000.f); float rcvTime = hsTimer::GetMilliSeconds<float>(rcvTicks);
// If the receiver takes more than 5 ms to process its message, log it // If the receiver takes more than 5 ms to process its message, log it
if (rcvTime > 5.f) if (rcvTime > 5.f)
plDispatchLogBase::GetInstance()->LogLongReceive(keyname.c_str(), className, clonePlayerID, msg, rcvTime); plDispatchLogBase::GetInstance()->LogLongReceive(keyname.c_str(), className, clonePlayerID, msg, rcvTime);
@ -392,7 +392,7 @@ void plDispatch::IMsgDispatch()
// for message logging // for message logging
// if (plDispatchLogBase::IsLogging()) // if (plDispatchLogBase::IsLogging())
// { // {
// float sendTime = hsTimer::FullTicksToMs(hsTimer::GetFullTickCount() - startTicks); // float sendTime = hsTimer::GetMilliSeconds<float>(hsTimer::GetTicks() - startTicks);
// //
// plDispatchLogBase::GetInstance()->DumpMsg(msg, numReceivers, (int)sendTime, responseLevel*2 /* indent */); // plDispatchLogBase::GetInstance()->DumpMsg(msg, numReceivers, (int)sendTime, responseLevel*2 /* indent */);
// if (origTail==fMsgCurrent) // if (origTail==fMsgCurrent)

42
Sources/Plasma/NucleusLib/pnTimer/hsTimer.cpp

@ -44,9 +44,6 @@ You can contact Cyan Worlds, Inc. by email legal@cyan.com
#include "plTweak.h" #include "plTweak.h"
typedef std::chrono::duration<double> dSeconds;
typedef std::chrono::duration<double, std::milli> dMilliseconds;
// //
// plTimerShare - the actual worker. All process spaces should share a single // plTimerShare - the actual worker. All process spaces should share a single
// plTimerShare to keep time synchronized across spaces. // plTimerShare to keep time synchronized across spaces.
@ -71,14 +68,12 @@ plTimerShare::~plTimerShare()
{ {
} }
double plTimerShare::GetSeconds() const uint64_t plTimerShare::GetTicks() const
{ {
return dSeconds(GetRawTicks()).count(); plTimerShare::Duration d = plTimerShare::Clock::now().time_since_epoch();
} typedef std::chrono::duration<uint64_t, plTimerShare::Clock::period> ticks;
double plTimerShare::GetMilliSeconds() const return std::chrono::duration_cast<ticks>(d).count();
{
return dMilliseconds(GetRawTicks()).count();
} }
double plTimerShare::IncSysSeconds() double plTimerShare::IncSysSeconds()
@ -194,8 +189,7 @@ plTimerShare::Duration plTimerShare::GetRawTicks() const
// //
// hsTimer - thin static interface to plTimerShare. Also keeps a couple of // hsTimer - thin static interface to plTimerShare.
// constants.
// //
static plTimerShare staticTimer; static plTimerShare staticTimer;
plTimerShare* hsTimer::fTimer = &staticTimer; // until overridden. plTimerShare* hsTimer::fTimer = &staticTimer; // until overridden.
@ -204,29 +198,3 @@ void hsTimer::SetTheTimer(plTimerShare* timer)
{ {
fTimer = timer; fTimer = timer;
} }
double hsTimer::GetPrecTicksPerSec()
{
return double(plTimerShare::Clock::period::num) /
double(plTimerShare::Clock::period::den);
}
uint32_t hsTimer::GetPrecTickCount()
{
return uint32_t(plTimerShare::Clock::now().time_since_epoch().count());
}
double hsTimer::PrecTicksToSecs(uint32_t ticks)
{
return dSeconds(plTimerShare::Duration(ticks)).count();
}
uint64_t hsTimer::GetFullTickCount()
{
return uint64_t(plTimerShare::Clock::now().time_since_epoch().count());
}
float hsTimer::FullTicksToMs(uint64_t ticks)
{
return float(dMilliseconds(plTimerShare::Duration(ticks)).count());
}

2
Sources/Plasma/PubUtilLib/plPipeline/plDTProgressMgr.cpp

@ -153,7 +153,7 @@ void plDTProgressMgr::Draw( plPipeline *p )
if (fActivePlate) if (fActivePlate)
{ {
float currentMs = hsTimer::FullTicksToMs(hsTimer::GetFullTickCount()); float currentMs = hsTimer::GetMilliSeconds<float>();
if ((currentMs - fLastDraw) > 30) if ((currentMs - fLastDraw) > 30)
{ {
fCurrentImage++; fCurrentImage++;

14
Sources/Plasma/PubUtilLib/plResMgr/plResManager.cpp

@ -355,7 +355,7 @@ bool plResManager::IReadObject(plKeyImp* pKey, hsStream *stream)
uint64_t startTotalTime = totalTime; uint64_t startTotalTime = totalTime;
uint64_t startTime = 0; uint64_t startTime = 0;
if (fLogReadTimes) if (fLogReadTimes)
startTime = hsTimer::GetFullTickCount(); startTime = hsTimer::GetTicks();
hsKeyedObject* ko = nil; hsKeyedObject* ko = nil;
@ -449,7 +449,7 @@ bool plResManager::IReadObject(plKeyImp* pKey, hsStream *stream)
if (fLogReadTimes) if (fLogReadTimes)
{ {
uint64_t ourTime = hsTimer::GetFullTickCount() - startTime; uint64_t ourTime = hsTimer::GetTicks() - startTime;
uint64_t childTime = totalTime - startTotalTime; uint64_t childTime = totalTime - startTotalTime;
ourTime -= childTime; ourTime -= childTime;
@ -457,9 +457,9 @@ bool plResManager::IReadObject(plKeyImp* pKey, hsStream *stream)
pKey->GetUoid().GetObjectName().c_str(), pKey->GetUoid().GetObjectName().c_str(),
plFactory::GetNameOfClass(pKey->GetUoid().GetClassType()), plFactory::GetNameOfClass(pKey->GetUoid().GetClassType()),
pKey->GetDataLen(), pKey->GetDataLen(),
hsTimer::FullTicksToMs(ourTime)); hsTimer::GetMilliSeconds<float>(ourTime));
totalTime += (hsTimer::GetFullTickCount() - startTime) - childTime; totalTime += (hsTimer::GetTicks() - startTime) - childTime;
} }
return (ko != nil); return (ko != nil);
@ -1132,7 +1132,7 @@ void plResManager::PageInRoom(const plLocation& page, uint16_t objClassToRef, pl
{ {
uint64_t readRoomTime = 0; uint64_t readRoomTime = 0;
if (fLogReadTimes) if (fLogReadTimes)
readRoomTime = hsTimer::GetFullTickCount(); readRoomTime = hsTimer::GetTicks();
plSynchEnabler ps(false); // disable dirty tracking while paging in plSynchEnabler ps(false); // disable dirty tracking while paging in
@ -1218,11 +1218,11 @@ void plResManager::PageInRoom(const plLocation& page, uint16_t objClassToRef, pl
if (fLogReadTimes) if (fLogReadTimes)
{ {
readRoomTime = hsTimer::GetFullTickCount() - readRoomTime; readRoomTime = hsTimer::GetTicks() - readRoomTime;
plStatusLog::AddLineS("readtimings.log", plStatusLog::kWhite, "----- Reading page %s>%s took %.1f ms", plStatusLog::AddLineS("readtimings.log", plStatusLog::kWhite, "----- Reading page %s>%s took %.1f ms",
pageNode->GetPageInfo().GetAge().c_str(), pageNode->GetPageInfo().GetPage().c_str(), pageNode->GetPageInfo().GetAge().c_str(), pageNode->GetPageInfo().GetPage().c_str(),
hsTimer::FullTicksToMs(readRoomTime)); hsTimer::GetMilliSeconds<float>(readRoomTime));
} }
} }

6
Sources/Plasma/PubUtilLib/plStatGather/plAutoProfile.cpp

@ -337,7 +337,7 @@ bool plAutoProfileImp::MsgReceive(plMessage* msg)
{ {
if (!ageLoaded->fLoaded) if (!ageLoaded->fLoaded)
{ {
fLinkTime = hsTimer::GetFullTickCount(); fLinkTime = hsTimer::GetTicks();
hsStatusMessage("Age unloaded"); hsStatusMessage("Age unloaded");
} }
return true; return true;
@ -348,8 +348,8 @@ bool plAutoProfileImp::MsgReceive(plMessage* msg)
{ {
if (fNextAge > 0) if (fNextAge > 0)
{ {
fLinkTime = hsTimer::GetFullTickCount() - fLinkTime; fLinkTime = hsTimer::GetTicks() - fLinkTime;
float ms = hsTimer::FullTicksToMs(fLinkTime); float ms = hsTimer::GetMilliSeconds<float>(fLinkTime);
hsStatusMessageF("Age %s finished load, took %.1f ms", hsStatusMessageF("Age %s finished load, took %.1f ms",
fAges[fNextAge-1].c_str(), fAges[fNextAge-1].c_str(),

Loading…
Cancel
Save