SH-3275 FIX interesting Update viewer metrics system to be more flexible

fixed anamolous LLFastTimer timings
meow-7.2.2
Richard Linden 2013-02-09 00:34:59 -08:00
parent 87f04a6dcc
commit 2e15e8fd4b
4 changed files with 45 additions and 23 deletions

View File

@ -256,12 +256,16 @@ void TimeBlock::processTimes()
while(cur_timer && cur_timer->mParentTimerData.mActiveTimer != cur_timer)
{
U64 cumulative_time_delta = cur_time - cur_timer->mStartTime;
accumulator->mChildTimeCounter += stack_record->mChildTime - (accumulator->mSelfTimeCounter - cur_timer->mStartSelfTimeCount);
accumulator->mSelfTimeCounter += cumulative_time_delta - stack_record->mChildTime;
U64 child_time = stack_record->mChildTime
- (accumulator->mSelfTimeCounter - cur_timer->mStartSelfTimeCounter)
- (accumulator->mChildTimeCounter - cur_timer->mStartChildTimeCounter);
accumulator->mChildTimeCounter += child_time;
accumulator->mSelfTimeCounter += cumulative_time_delta - child_time;
stack_record->mChildTime = 0;
cur_timer->mStartTime = cur_time;
cur_timer->mStartSelfTimeCounter = accumulator->mSelfTimeCounter;
cur_timer->mStartChildTimeCounter = accumulator->mChildTimeCounter;
stack_record = &cur_timer->mParentTimerData;
accumulator = stack_record->mTimeBlock->getPrimaryAccumulator();
@ -402,6 +406,8 @@ void TimeBlock::writeLog(std::ostream& os)
TimeBlockAccumulator::TimeBlockAccumulator()
: mChildTimeCounter(0),
mSelfTimeCounter(0),
mStartChildTimeCounter(0),
mStartSelfTimeCounter(0),
mCalls(0),
mLastCaller(NULL),
mActiveCount(0),
@ -411,8 +417,8 @@ TimeBlockAccumulator::TimeBlockAccumulator()
void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other )
{
mChildTimeCounter += other.mChildTimeCounter;
mSelfTimeCounter += other.mSelfTimeCounter;
mChildTimeCounter += other.mChildTimeCounter - other.mStartChildTimeCounter;
mSelfTimeCounter += other.mSelfTimeCounter - other.mStartSelfTimeCounter;
mCalls += other.mCalls;
mLastCaller = other.mLastCaller;
mActiveCount = other.mActiveCount;
@ -422,16 +428,24 @@ void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other )
void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other )
{
mSelfTimeCounter = 0;
mChildTimeCounter = 0;
mCalls = 0;
if (other)
{
mStartSelfTimeCounter = other->mSelfTimeCounter;
mSelfTimeCounter = mStartSelfTimeCounter;
mStartChildTimeCounter = other->mChildTimeCounter;
mChildTimeCounter = mStartChildTimeCounter;
mLastCaller = other->mLastCaller;
mActiveCount = other->mActiveCount;
mMoveUpTree = other->mMoveUpTree;
mParent = other->mParent;
}
else
{
mStartSelfTimeCounter = mSelfTimeCounter;
mStartChildTimeCounter = mChildTimeCounter;
}
}
LLUnit<LLUnits::Seconds, F64> BlockTimer::getElapsedTime()

View File

@ -76,7 +76,8 @@ public:
private:
U64 mStartTime;
U64 mStartSelfTimeCount;
U64 mStartSelfTimeCounter;
U64 mStartChildTimeCounter;
BlockTimerStackRecord mParentTimerData;
};
@ -282,7 +283,8 @@ LL_FORCE_INLINE BlockTimer::BlockTimer(TimeBlock& timer)
BlockTimerStackRecord* cur_timer_data = ThreadTimerStack::getIfExists();
TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator();
accumulator->mActiveCount++;
mStartSelfTimeCount = accumulator->mSelfTimeCounter;
mStartSelfTimeCounter = accumulator->mSelfTimeCounter;
mStartChildTimeCounter = accumulator->mChildTimeCounter;
// keep current parent as long as it is active when we are
accumulator->mMoveUpTree |= (accumulator->mParent->getPrimaryAccumulator()->mActiveCount == 0);
@ -302,10 +304,12 @@ LL_FORCE_INLINE BlockTimer::~BlockTimer()
BlockTimerStackRecord* cur_timer_data = ThreadTimerStack::getIfExists();
TimeBlockAccumulator* accumulator = cur_timer_data->mTimeBlock->getPrimaryAccumulator();
U64 child_time = cur_timer_data->mChildTime - (accumulator->mSelfTimeCounter - mStartSelfTimeCount);
U64 child_time = cur_timer_data->mChildTime
- (accumulator->mSelfTimeCounter - mStartSelfTimeCounter)
- (accumulator->mChildTimeCounter - mStartChildTimeCounter);
accumulator->mCalls++;
accumulator->mChildTimeCounter += child_time;
accumulator->mSelfTimeCounter += total_time - child_time;
accumulator->mSelfTimeCounter += total_time - cur_timer_data->mChildTime;
accumulator->mActiveCount--;
// store last caller to bootstrap tree creation
@ -320,11 +324,6 @@ LL_FORCE_INLINE BlockTimer::~BlockTimer()
#endif
}
inline void BlockTimer::logCurrentTime()
{
U64 total_time = TimeBlock::getCPUClockCount64() - mStartTime;
llinfos << "Time elapsed: " << (1000.0 * (F64)total_time / (F64)TimeBlock::countsPerSecond()) << llendl;
}
}
typedef LLTrace::BlockTimer LLFastTimer;

View File

@ -444,7 +444,9 @@ namespace LLTrace
//
// members
//
U64 mChildTimeCounter,
U64 mStartChildTimeCounter,
mStartSelfTimeCounter,
mChildTimeCounter,
mSelfTimeCounter;
U32 mCalls;
class TimeBlock* mParent; // last acknowledged parent of this time block

View File

@ -120,8 +120,6 @@ void Recording::syncTo(Recording& other)
other.mMeasurements.write()->reset(mMeasurements);
other.mStackTimers.write()->reset(mStackTimers);
other.mMemStats.write()->reset(mMemStats);
//TODO: figure out how to get seamless handoff of timing stats
}
void Recording::makePrimary()
@ -184,12 +182,15 @@ void Recording::mergeRecording( const Recording& other)
LLUnit<LLUnits::Seconds, F64> Recording::getSum(const TraceType<TimeBlockAccumulator>& stat) const
{
return ((F64)(*mStackTimers)[stat.getIndex()].mSelfTimeCounter + (F64)(*mStackTimers)[stat.getIndex()].mChildTimeCounter) / (F64)LLTrace::TimeBlock::countsPerSecond();
const TimeBlockAccumulator& accumulator = (*mStackTimers)[stat.getIndex()];
return (F64)(accumulator.mSelfTimeCounter - accumulator.mStartSelfTimeCounter + accumulator.mChildTimeCounter - accumulator.mStartChildTimeCounter)
/ (F64)LLTrace::TimeBlock::countsPerSecond();
}
LLUnit<LLUnits::Seconds, F64> Recording::getSum(const TraceType<TimeBlockAccumulator::SelfTimeAspect>& stat) const
{
return (F64)(*mStackTimers)[stat.getIndex()].mSelfTimeCounter / (F64)LLTrace::TimeBlock::countsPerSecond();
const TimeBlockAccumulator& accumulator = (*mStackTimers)[stat.getIndex()];
return (F64)(accumulator.mSelfTimeCounter - accumulator.mStartSelfTimeCounter) / (F64)LLTrace::TimeBlock::countsPerSecond();
}
@ -200,12 +201,18 @@ U32 Recording::getSum(const TraceType<TimeBlockAccumulator::CallCountAspect>& st
LLUnit<LLUnits::Seconds, F64> Recording::getPerSec(const TraceType<TimeBlockAccumulator>& stat) const
{
return ((F64)(*mStackTimers)[stat.getIndex()].mSelfTimeCounter + (F64)(*mStackTimers)[stat.getIndex()].mChildTimeCounter) / ((F64)LLTrace::TimeBlock::countsPerSecond() * mElapsedSeconds);
const TimeBlockAccumulator& accumulator = (*mStackTimers)[stat.getIndex()];
return (F64)(accumulator.mSelfTimeCounter - accumulator.mStartSelfTimeCounter + accumulator.mChildTimeCounter - accumulator.mStartChildTimeCounter)
/ ((F64)LLTrace::TimeBlock::countsPerSecond() * mElapsedSeconds);
}
LLUnit<LLUnits::Seconds, F64> Recording::getPerSec(const TraceType<TimeBlockAccumulator::SelfTimeAspect>& stat) const
{
return (F64)(*mStackTimers)[stat.getIndex()].mSelfTimeCounter / ((F64)LLTrace::TimeBlock::countsPerSecond() * mElapsedSeconds);
const TimeBlockAccumulator& accumulator = (*mStackTimers)[stat.getIndex()];
return (F64)(accumulator.mSelfTimeCounter - accumulator.mStartSelfTimeCounter)
/ ((F64)LLTrace::TimeBlock::countsPerSecond() * mElapsedSeconds);
}
F32 Recording::getPerSec(const TraceType<TimeBlockAccumulator::CallCountAspect>& stat) const