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

fix for timings for recursive fast timers not being correct

5 files changed, 23 insertions, 13 deletions

diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp
index e58c5c0f98..809a0ef4bf 100644
--- a/indra/llcommon/llfasttimer.cpp
+++ b/indra/llcommon/llfasttimer.cpp
@@ -257,8 +257,8 @@ void TimeBlock::processTimes()
 	{
 		U64 cumulative_time_delta = cur_time - cur_timer->mStartTime;
 	
-		accumulator->mTotalTimeCounter += cumulative_time_delta;
-		accumulator->mChildTimeCounter += stack_record->mChildTime;
+		accumulator->mChildTimeCounter += stack_record->mChildTime - (accumulator->mSelfTimeCounter - cur_timer->mStartSelfTimeCount);
+		accumulator->mSelfTimeCounter += cumulative_time_delta - stack_record->mChildTime;
 		stack_record->mChildTime = 0;
 
 		cur_timer->mStartTime = cur_time;
@@ -401,7 +401,7 @@ void TimeBlock::writeLog(std::ostream& os)
 
 TimeBlockAccumulator::TimeBlockAccumulator() 
 :	mChildTimeCounter(0),
-	mTotalTimeCounter(0),
+	mSelfTimeCounter(0),
 	mCalls(0),
 	mLastCaller(NULL),
 	mActiveCount(0),
@@ -412,7 +412,7 @@ TimeBlockAccumulator::TimeBlockAccumulator()
 void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other )
 {
 	mChildTimeCounter += other.mChildTimeCounter;
-	mTotalTimeCounter += other.mTotalTimeCounter;
+	mSelfTimeCounter += other.mSelfTimeCounter;
 	mCalls += other.mCalls;
 	mLastCaller = other.mLastCaller;
 	mActiveCount = other.mActiveCount;
@@ -422,7 +422,7 @@ void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other )
 
 void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other )
 {
-	mTotalTimeCounter = 0;
+	mSelfTimeCounter = 0;
 	mChildTimeCounter = 0;
 	mCalls = 0;
 	if (other)
diff --git a/indra/llcommon/llfasttimer.h b/indra/llcommon/llfasttimer.h
index 726db70fbe..9402bb7267 100644
--- a/indra/llcommon/llfasttimer.h
+++ b/indra/llcommon/llfasttimer.h
@@ -71,9 +71,12 @@ public:
 	BlockTimer(TimeBlock& timer);
 	~BlockTimer();
 
+	void logCurrentTime();
+
 private:
 
 	U64						mStartTime;
+	U64						mStartSelfTimeCount;
 	BlockTimerStackRecord	mParentTimerData;
 };
 
@@ -279,6 +282,7 @@ LL_FORCE_INLINE BlockTimer::BlockTimer(TimeBlock& timer)
 	BlockTimerStackRecord* cur_timer_data = ThreadTimerStack::getIfExists();
 	TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator();
 	accumulator->mActiveCount++;
+	mStartSelfTimeCount = accumulator->mSelfTimeCounter;
 	// keep current parent as long as it is active when we are
 	accumulator->mMoveUpTree |= (accumulator->mParent->getPrimaryAccumulator()->mActiveCount == 0);
 
@@ -298,9 +302,10 @@ 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);
 	accumulator->mCalls++;
-	accumulator->mChildTimeCounter += cur_timer_data->mChildTime;
-	accumulator->mTotalTimeCounter += total_time;
+	accumulator->mChildTimeCounter += child_time;
+	accumulator->mSelfTimeCounter += total_time - child_time;
 	accumulator->mActiveCount--;
 
 	// store last caller to bootstrap tree creation
@@ -315,6 +320,11 @@ 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; 
diff --git a/indra/llcommon/lltrace.h b/indra/llcommon/lltrace.h
index c38e92962b..9eadd8a2be 100644
--- a/indra/llcommon/lltrace.h
+++ b/indra/llcommon/lltrace.h
@@ -445,7 +445,7 @@ namespace LLTrace
 		// members
 		//
 		U64							mChildTimeCounter,
-									mTotalTimeCounter;
+									mSelfTimeCounter;
 		U32							mCalls;
 		class TimeBlock*			mParent;		// last acknowledged parent of this time block
 		class TimeBlock*			mLastCaller;	// used to bootstrap tree construction
diff --git a/indra/llcommon/lltracerecording.cpp b/indra/llcommon/lltracerecording.cpp
index 29604f7155..69085ddcc2 100644
--- a/indra/llcommon/lltracerecording.cpp
+++ b/indra/llcommon/lltracerecording.cpp
@@ -184,12 +184,12 @@ void Recording::mergeRecording( const Recording& other)
 
 LLUnit<LLUnits::Seconds, F64> Recording::getSum(const TraceType<TimeBlockAccumulator>& stat) const
 {
-	return (F64)(*mStackTimers)[stat.getIndex()].mTotalTimeCounter / (F64)LLTrace::TimeBlock::countsPerSecond();
+	return ((F64)(*mStackTimers)[stat.getIndex()].mSelfTimeCounter + (F64)(*mStackTimers)[stat.getIndex()].mChildTimeCounter) / (F64)LLTrace::TimeBlock::countsPerSecond();
 }
 
 LLUnit<LLUnits::Seconds, F64> Recording::getSum(const TraceType<TimeBlockAccumulator::SelfTimeAspect>& stat) const
 {
-	return ((F64)(*mStackTimers)[stat.getIndex()].mTotalTimeCounter - (F64)(*mStackTimers)[stat.getIndex()].mChildTimeCounter) / (F64)LLTrace::TimeBlock::countsPerSecond();
+	return (F64)(*mStackTimers)[stat.getIndex()].mSelfTimeCounter / (F64)LLTrace::TimeBlock::countsPerSecond();
 }
 
 
@@ -200,12 +200,12 @@ U32 Recording::getSum(const TraceType<TimeBlockAccumulator::CallCountAspect>& st
 
 LLUnit<LLUnits::Seconds, F64> Recording::getPerSec(const TraceType<TimeBlockAccumulator>& stat) const
 {
-	return (F64)(*mStackTimers)[stat.getIndex()].mTotalTimeCounter / ((F64)LLTrace::TimeBlock::countsPerSecond() * mElapsedSeconds);
+	return ((F64)(*mStackTimers)[stat.getIndex()].mSelfTimeCounter + (F64)(*mStackTimers)[stat.getIndex()].mChildTimeCounter) / ((F64)LLTrace::TimeBlock::countsPerSecond() * mElapsedSeconds);
 }
 
 LLUnit<LLUnits::Seconds, F64> Recording::getPerSec(const TraceType<TimeBlockAccumulator::SelfTimeAspect>& stat) const
 {
-	return ((F64)(*mStackTimers)[stat.getIndex()].mTotalTimeCounter - (F64)(*mStackTimers)[stat.getIndex()].mChildTimeCounter) / ((F64)LLTrace::TimeBlock::countsPerSecond() * mElapsedSeconds);
+	return (F64)(*mStackTimers)[stat.getIndex()].mSelfTimeCounter / ((F64)LLTrace::TimeBlock::countsPerSecond() * mElapsedSeconds);
 }
 
 F32 Recording::getPerSec(const TraceType<TimeBlockAccumulator::CallCountAspect>& stat) const
diff --git a/indra/newview/llfasttimerview.cpp b/indra/newview/llfasttimerview.cpp
index 7d23687e21..1a1a4a8b44 100644
--- a/indra/newview/llfasttimerview.cpp
+++ b/indra/newview/llfasttimerview.cpp
@@ -1403,7 +1403,7 @@ void LLFastTimerView::updateTotalTime()
 		break;
 	}
 
-	mTotalTimeDisplay = LLUnit<LLUnits::Milliseconds, F64>(llceil(mTotalTimeDisplay.as<LLUnits::Milliseconds, F64>().value() / (20.f)) * 20.f);
+	mTotalTimeDisplay = LLUnit<LLUnits::Milliseconds, F32>(llceil(mTotalTimeDisplay.as<LLUnits::Milliseconds, F32>().value() / (20.f)) * 20.f);
 }
 
 void LLFastTimerView::drawBars()