summaryrefslogtreecommitdiff
path: root/indra/llcommon/llfasttimer.cpp
diff options
context:
space:
mode:
authorRichard Linden <none@none>2013-03-22 00:44:59 -0700
committerRichard Linden <none@none>2013-03-22 00:44:59 -0700
commit68f9f656cd22332e46959a90347e38f79c19a66c (patch)
tree531d87287b69f500c5901f785e60483555b415f9 /indra/llcommon/llfasttimer.cpp
parente87000ba0750e55d9d6b55feccc4124f5d2b4b74 (diff)
parent368dd542bec7c31e14673b83d3342c35717d2920 (diff)
merge with viewer-release
Diffstat (limited to 'indra/llcommon/llfasttimer.cpp')
-rw-r--r--indra/llcommon/llfasttimer.cpp609
1 files changed, 203 insertions, 406 deletions
diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp
index 6970c29092..fbffe133f1 100644
--- a/indra/llcommon/llfasttimer.cpp
+++ b/indra/llcommon/llfasttimer.cpp
@@ -32,8 +32,13 @@
#include "llsingleton.h"
#include "lltreeiterators.h"
#include "llsdserialize.h"
+#include "llunit.h"
+#include "llsd.h"
+#include "lltracerecording.h"
+#include "lltracethreadrecorder.h"
#include <boost/bind.hpp>
+#include <queue>
#if LL_WINDOWS
@@ -49,37 +54,36 @@
#error "architecture not supported"
#endif
+namespace LLTrace
+{
+
//////////////////////////////////////////////////////////////////////////////
// statics
-S32 LLFastTimer::sCurFrameIndex = -1;
-S32 LLFastTimer::sLastFrameIndex = -1;
-U64 LLFastTimer::sLastFrameTime = LLFastTimer::getCPUClockCount64();
-bool LLFastTimer::sPauseHistory = 0;
-bool LLFastTimer::sResetHistory = 0;
-LLFastTimer::CurTimerData LLFastTimer::sCurTimerData;
-BOOL LLFastTimer::sLog = FALSE;
-std::string LLFastTimer::sLogName = "";
-BOOL LLFastTimer::sMetricLog = FALSE;
-LLMutex* LLFastTimer::sLogLock = NULL;
-std::queue<LLSD> LLFastTimer::sLogQueue;
+bool TimeBlock::sLog = false;
+std::string TimeBlock::sLogName = "";
+bool TimeBlock::sMetricLog = false;
#if LL_LINUX || LL_SOLARIS
-U64 LLFastTimer::sClockResolution = 1000000000; // Nanosecond resolution
+U64 TimeBlock::sClockResolution = 1000000000; // Nanosecond resolution
#else
-U64 LLFastTimer::sClockResolution = 1000000; // Microsecond resolution
+U64 TimeBlock::sClockResolution = 1000000; // Microsecond resolution
#endif
+static LLMutex* sLogLock = NULL;
+static std::queue<LLSD> sLogQueue;
+
+
// FIXME: move these declarations to the relevant modules
// helper functions
-typedef LLTreeDFSPostIter<LLFastTimer::NamedTimer, LLFastTimer::NamedTimer::child_const_iter> timer_tree_bottom_up_iterator_t;
+typedef LLTreeDFSPostIter<TimeBlock, TimeBlock::child_const_iter> timer_tree_bottom_up_iterator_t;
-static timer_tree_bottom_up_iterator_t begin_timer_tree_bottom_up(LLFastTimer::NamedTimer& id)
+static timer_tree_bottom_up_iterator_t begin_timer_tree_bottom_up(TimeBlock& id)
{
return timer_tree_bottom_up_iterator_t(&id,
- boost::bind(boost::mem_fn(&LLFastTimer::NamedTimer::beginChildren), _1),
- boost::bind(boost::mem_fn(&LLFastTimer::NamedTimer::endChildren), _1));
+ boost::bind(boost::mem_fn(&TimeBlock::beginChildren), _1),
+ boost::bind(boost::mem_fn(&TimeBlock::endChildren), _1));
}
static timer_tree_bottom_up_iterator_t end_timer_tree_bottom_up()
@@ -87,14 +91,14 @@ static timer_tree_bottom_up_iterator_t end_timer_tree_bottom_up()
return timer_tree_bottom_up_iterator_t();
}
-typedef LLTreeDFSIter<LLFastTimer::NamedTimer, LLFastTimer::NamedTimer::child_const_iter> timer_tree_dfs_iterator_t;
+typedef LLTreeDFSIter<TimeBlock, TimeBlock::child_const_iter> timer_tree_dfs_iterator_t;
-static timer_tree_dfs_iterator_t begin_timer_tree(LLFastTimer::NamedTimer& id)
+static timer_tree_dfs_iterator_t begin_timer_tree(TimeBlock& id)
{
return timer_tree_dfs_iterator_t(&id,
- boost::bind(boost::mem_fn(&LLFastTimer::NamedTimer::beginChildren), _1),
- boost::bind(boost::mem_fn(&LLFastTimer::NamedTimer::endChildren), _1));
+ boost::bind(boost::mem_fn(&TimeBlock::beginChildren), _1),
+ boost::bind(boost::mem_fn(&TimeBlock::endChildren), _1));
}
static timer_tree_dfs_iterator_t end_timer_tree()
@@ -102,90 +106,48 @@ static timer_tree_dfs_iterator_t end_timer_tree()
return timer_tree_dfs_iterator_t();
}
-// factory class that creates NamedTimers via static DeclareTimer objects
-class NamedTimerFactory : public LLSingleton<NamedTimerFactory>
-{
-public:
- NamedTimerFactory()
- : mTimerRoot(NULL)
- {}
- /*virtual */ void initSingleton()
+// sort child timers by name
+struct SortTimerByName
+{
+ bool operator()(const TimeBlock* i1, const TimeBlock* i2)
{
- mTimerRoot = new LLFastTimer::NamedTimer("root");
- mRootFrameState.setNamedTimer(mTimerRoot);
- mTimerRoot->setFrameState(&mRootFrameState);
- mTimerRoot->mParent = mTimerRoot;
- mTimerRoot->setCollapsed(false);
- mRootFrameState.mParent = &mRootFrameState;
+ return i1->getName() < i2->getName();
}
+};
- ~NamedTimerFactory()
+TimeBlock& TimeBlock::getRootTimeBlock()
{
- std::for_each(mTimers.begin(), mTimers.end(), DeletePairedPointer());
-
- delete mTimerRoot;
+ static TimeBlock root_timer("root", true, NULL);
+ return root_timer;
}
- LLFastTimer::NamedTimer& createNamedTimer(const std::string& name, LLFastTimer::FrameState* state)
+void TimeBlock::pushLog(LLSD log)
{
- LLFastTimer::NamedTimer* timer = new LLFastTimer::NamedTimer(name);
- timer->setFrameState(state);
- timer->setParent(mTimerRoot);
- mTimers.insert(std::make_pair(name, timer));
-
- return *timer;
- }
+ LLMutexLock lock(sLogLock);
- LLFastTimer::NamedTimer* getTimerByName(const std::string& name)
- {
- timer_map_t::iterator found_it = mTimers.find(name);
- if (found_it != mTimers.end())
- {
- return found_it->second;
- }
- return NULL;
+ sLogQueue.push(log);
}
- LLFastTimer::NamedTimer* getRootTimer() { return mTimerRoot; }
-
- typedef std::multimap<std::string, LLFastTimer::NamedTimer*> timer_map_t;
- timer_map_t::iterator beginTimers() { return mTimers.begin(); }
- timer_map_t::iterator endTimers() { return mTimers.end(); }
- S32 timerCount() { return mTimers.size(); }
-
-private:
- timer_map_t mTimers;
-
- LLFastTimer::NamedTimer* mTimerRoot;
- LLFastTimer::FrameState mRootFrameState;
-};
-
-LLFastTimer::DeclareTimer::DeclareTimer(const std::string& name, bool open )
-: mTimer(NamedTimerFactory::instance().createNamedTimer(name, &mFrameState))
+void TimeBlock::setLogLock(LLMutex* lock)
{
- mTimer.setCollapsed(!open);
+ sLogLock = lock;
}
-LLFastTimer::DeclareTimer::DeclareTimer(const std::string& name)
-: mTimer(NamedTimerFactory::instance().createNamedTimer(name, &mFrameState))
-{
-}
//static
#if (LL_DARWIN || LL_LINUX || LL_SOLARIS) && !(defined(__i386__) || defined(__amd64__))
-U64 LLFastTimer::countsPerSecond() // counts per second for the *32-bit* timer
+U64 TimeBlock::countsPerSecond()
{
- return sClockResolution >> 8;
+ return sClockResolution;
}
#else // windows or x86-mac or x86-linux or x86-solaris
-U64 LLFastTimer::countsPerSecond() // counts per second for the *32-bit* timer
+U64 TimeBlock::countsPerSecond()
{
#if LL_FASTTIMER_USE_RDTSC || !LL_WINDOWS
//getCPUFrequency returns MHz and sCPUClockFrequency wants to be in Hz
- static U64 sCPUClockFrequency = U64(LLProcessorInfo().getCPUFrequency()*1000000.0);
+ static LLUnit<LLUnits::Hertz, U64> sCPUClockFrequency = LLProcessorInfo().getCPUFrequency();
- // we drop the low-order byte in our timers, so report a lower frequency
#else
// If we're not using RDTSC, each fasttimer tick is just a performance counter tick.
// Not redefining the clock frequency itself (in llprocessor.cpp/calculate_cpu_frequency())
@@ -198,269 +160,185 @@ U64 LLFastTimer::countsPerSecond() // counts per second for the *32-bit* timer
firstcall = false;
}
#endif
- return sCPUClockFrequency >> 8;
+ return sCPUClockFrequency.value();
}
#endif
-LLFastTimer::FrameState::FrameState()
-: mActiveCount(0),
- mCalls(0),
- mSelfTimeCounter(0),
- mParent(NULL),
- mLastCaller(NULL),
- mMoveUpTree(false)
-{}
-
-
-LLFastTimer::NamedTimer::NamedTimer(const std::string& name)
-: mName(name),
- mCollapsed(true),
- mParent(NULL),
- mTotalTimeCounter(0),
- mCountAverage(0),
- mCallAverage(0),
- mNeedsSorting(false),
- mFrameState(NULL)
-{
- mCountHistory = new U32[HISTORY_NUM];
- memset(mCountHistory, 0, sizeof(U32) * HISTORY_NUM);
- mCallHistory = new U32[HISTORY_NUM];
- memset(mCallHistory, 0, sizeof(U32) * HISTORY_NUM);
-}
-
-LLFastTimer::NamedTimer::~NamedTimer()
+TimeBlock::TimeBlock(const char* name, bool open, TimeBlock* parent)
+: TraceType<TimeBlockAccumulator>(name),
+ mCollapsed(true)
{
- delete[] mCountHistory;
- delete[] mCallHistory;
+ setCollapsed(!open);
}
-std::string LLFastTimer::NamedTimer::getToolTip(S32 history_idx)
+TimeBlockTreeNode& TimeBlock::getTreeNode() const
{
- F64 ms_multiplier = 1000.0 / (F64)LLFastTimer::countsPerSecond();
- if (history_idx < 0)
- {
- // by default, show average number of call
- return llformat("%s (%d ms, %d calls)", getName().c_str(), (S32)(getCountAverage() * ms_multiplier), (S32)getCallAverage());
- }
- else
- {
- return llformat("%s (%d ms, %d calls)", getName().c_str(), (S32)(getHistoricalCount(history_idx) * ms_multiplier), (S32)getHistoricalCalls(history_idx));
+ TimeBlockTreeNode* nodep = LLTrace::get_thread_recorder()->getTimeBlockTreeNode(getIndex());
+ llassert(nodep);
+ return *nodep;
}
-}
-
-void LLFastTimer::NamedTimer::setParent(NamedTimer* parent)
-{
- llassert_always(parent != this);
- llassert_always(parent != NULL);
-
- if (mParent)
- {
- // subtract our accumulated from previous parent
- for (S32 i = 0; i < HISTORY_NUM; i++)
- {
- mParent->mCountHistory[i] -= mCountHistory[i];
- }
-
- // subtract average timing from previous parent
- mParent->mCountAverage -= mCountAverage;
-
- std::vector<NamedTimer*>& children = mParent->getChildren();
- std::vector<NamedTimer*>::iterator found_it = std::find(children.begin(), children.end(), this);
- if (found_it != children.end())
- {
- children.erase(found_it);
- }
- }
-
- mParent = parent;
- if (parent)
- {
- getFrameState().mParent = &parent->getFrameState();
- parent->getChildren().push_back(this);
- parent->mNeedsSorting = true;
- }
-}
-
-S32 LLFastTimer::NamedTimer::getDepth()
-{
- S32 depth = 0;
- NamedTimer* timerp = mParent;
- while(timerp)
- {
- depth++;
- if (timerp->getParent() == timerp) break;
- timerp = timerp->mParent;
- }
- return depth;
-}
-
-// static
-void LLFastTimer::NamedTimer::processTimes()
-{
- if (sCurFrameIndex < 0) return;
-
- buildHierarchy();
- accumulateTimings();
-}
-
-// sort child timers by name
-struct SortTimerByName
-{
- bool operator()(const LLFastTimer::NamedTimer* i1, const LLFastTimer::NamedTimer* i2)
- {
- return i1->getName() < i2->getName();
- }
-};
//static
-void LLFastTimer::NamedTimer::buildHierarchy()
+void TimeBlock::processTimes()
{
- if (sCurFrameIndex < 0 ) return;
+ get_clock_count(); // good place to calculate clock frequency
+ U64 cur_time = getCPUClockCount64();
// set up initial tree
+ for (LLInstanceTracker<TimeBlock>::instance_iter it = LLInstanceTracker<TimeBlock>::beginInstances(), end_it = LLInstanceTracker<TimeBlock>::endInstances();
+ it != end_it;
+ ++it)
{
- for (instance_iter it = beginInstances(); it != endInstances(); ++it)
- {
- NamedTimer& timer = *it;
- if (&timer == NamedTimerFactory::instance().getRootTimer()) continue;
+ TimeBlock& timer = *it;
+ if (&timer == &TimeBlock::getRootTimeBlock()) continue;
// bootstrap tree construction by attaching to last timer to be on stack
// when this timer was called
- if (timer.getFrameState().mLastCaller && timer.mParent == NamedTimerFactory::instance().getRootTimer())
+ if (timer.getParent() == &TimeBlock::getRootTimeBlock())
+ {
+ TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator();
+
+ if (accumulator->mLastCaller)
{
- timer.setParent(timer.getFrameState().mLastCaller->mTimer);
- // no need to push up tree on first use, flag can be set spuriously
- timer.getFrameState().mMoveUpTree = false;
+ timer.setParent(accumulator->mLastCaller);
+ accumulator->mParent = accumulator->mLastCaller;
}
+ // no need to push up tree on first use, flag can be set spuriously
+ accumulator->mMoveUpTree = false;
}
}
- // bump timers up tree if they've been flagged as being in the wrong place
+ // bump timers up tree if they have been flagged as being in the wrong place
// do this in a bottom up order to promote descendants first before promoting ancestors
// this preserves partial order derived from current frame's observations
- for(timer_tree_bottom_up_iterator_t it = begin_timer_tree_bottom_up(*NamedTimerFactory::instance().getRootTimer());
+ for(timer_tree_bottom_up_iterator_t it = begin_timer_tree_bottom_up(TimeBlock::getRootTimeBlock());
it != end_timer_tree_bottom_up();
++it)
{
- NamedTimer* timerp = *it;
+ TimeBlock* timerp = *it;
+
+ // sort timers by time last called, so call graph makes sense
+ TimeBlockTreeNode& tree_node = timerp->getTreeNode();
+ if (tree_node.mNeedsSorting)
+ {
+ std::sort(tree_node.mChildren.begin(), tree_node.mChildren.end(), SortTimerByName());
+ }
+
// skip root timer
- if (timerp == NamedTimerFactory::instance().getRootTimer()) continue;
+ if (timerp != &TimeBlock::getRootTimeBlock())
+ {
+ TimeBlockAccumulator* accumulator = timerp->getPrimaryAccumulator();
- if (timerp->getFrameState().mMoveUpTree)
+ if (accumulator->mMoveUpTree)
{
- // since ancestors have already been visited, reparenting won't affect tree traversal
+ // since ancestors have already been visited, re-parenting won't affect tree traversal
//step up tree, bringing our descendants with us
LL_DEBUGS("FastTimers") << "Moving " << timerp->getName() << " from child of " << timerp->getParent()->getName() <<
" to child of " << timerp->getParent()->getParent()->getName() << LL_ENDL;
timerp->setParent(timerp->getParent()->getParent());
- timerp->getFrameState().mMoveUpTree = false;
+ accumulator->mParent = timerp->getParent();
+ accumulator->mMoveUpTree = false;
// don't bubble up any ancestors until descendants are done bubbling up
+ // as ancestors may call this timer only on certain paths, so we want to resolve
+ // child-most block locations before their parents
it.skipAncestors();
}
}
-
- // sort timers by time last called, so call graph makes sense
- for(timer_tree_dfs_iterator_t it = begin_timer_tree(*NamedTimerFactory::instance().getRootTimer());
- it != end_timer_tree();
- ++it)
- {
- NamedTimer* timerp = (*it);
- if (timerp->mNeedsSorting)
- {
- std::sort(timerp->getChildren().begin(), timerp->getChildren().end(), SortTimerByName());
- }
- timerp->mNeedsSorting = false;
- }
}
-//static
-void LLFastTimer::NamedTimer::accumulateTimings()
-{
- U32 cur_time = getCPUClockCount32();
-
// walk up stack of active timers and accumulate current time while leaving timing structures active
- LLFastTimer* cur_timer = sCurTimerData.mCurTimer;
+ BlockTimerStackRecord* stack_record = ThreadTimerStack::getInstance();
+ BlockTimer* cur_timer = stack_record->mActiveTimer;
+ TimeBlockAccumulator* accumulator = stack_record->mTimeBlock->getPrimaryAccumulator();
+
// root defined by parent pointing to self
- CurTimerData* cur_data = &sCurTimerData;
- while(cur_timer && cur_timer->mLastTimerData.mCurTimer != cur_timer)
+ while(cur_timer && cur_timer->mParentTimerData.mActiveTimer != cur_timer)
{
- U32 cumulative_time_delta = cur_time - cur_timer->mStartTime;
- U32 self_time_delta = cumulative_time_delta - cur_data->mChildTime;
- cur_data->mChildTime = 0;
- cur_timer->mFrameState->mSelfTimeCounter += self_time_delta;
+ U64 cumulative_time_delta = cur_time - cur_timer->mStartTime;
+ accumulator->mTotalTimeCounter += cumulative_time_delta - (accumulator->mTotalTimeCounter - cur_timer->mBlockStartTotalTimeCounter);
+ accumulator->mSelfTimeCounter += cumulative_time_delta - stack_record->mChildTime;
+ stack_record->mChildTime = 0;
+
cur_timer->mStartTime = cur_time;
+ cur_timer->mBlockStartTotalTimeCounter = accumulator->mTotalTimeCounter;
- cur_data = &cur_timer->mLastTimerData;
- cur_data->mChildTime += cumulative_time_delta;
+ stack_record = &cur_timer->mParentTimerData;
+ accumulator = stack_record->mTimeBlock->getPrimaryAccumulator();
+ cur_timer = stack_record->mActiveTimer;
- cur_timer = cur_timer->mLastTimerData.mCurTimer;
+ stack_record->mChildTime += cumulative_time_delta;
}
- // traverse tree in DFS post order, or bottom up
- for(timer_tree_bottom_up_iterator_t it = begin_timer_tree_bottom_up(*NamedTimerFactory::instance().getRootTimer());
- it != end_timer_tree_bottom_up();
+ // reset for next frame
+ for (LLInstanceTracker<TimeBlock>::instance_iter it = LLInstanceTracker<TimeBlock>::beginInstances(),
+ end_it = LLInstanceTracker<TimeBlock>::endInstances();
+ it != end_it;
++it)
{
- NamedTimer* timerp = (*it);
- timerp->mTotalTimeCounter = timerp->getFrameState().mSelfTimeCounter;
- for (child_const_iter child_it = timerp->beginChildren(); child_it != timerp->endChildren(); ++child_it)
+ TimeBlock& timer = *it;
+ TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator();
+
+ accumulator->mLastCaller = NULL;
+ accumulator->mMoveUpTree = false;
+ }
+}
+
+
+std::vector<TimeBlock*>::iterator TimeBlock::beginChildren()
{
- timerp->mTotalTimeCounter += (*child_it)->mTotalTimeCounter;
+ return getTreeNode().mChildren.begin();
}
- S32 cur_frame = sCurFrameIndex;
- if (cur_frame >= 0)
+std::vector<TimeBlock*>::iterator TimeBlock::endChildren()
{
- // update timer history
- int hidx = cur_frame % HISTORY_NUM;
+ return getTreeNode().mChildren.end();
+}
- timerp->mCountHistory[hidx] = timerp->mTotalTimeCounter;
- timerp->mCountAverage = ((U64)timerp->mCountAverage * cur_frame + timerp->mTotalTimeCounter) / (cur_frame+1);
- timerp->mCallHistory[hidx] = timerp->getFrameState().mCalls;
- timerp->mCallAverage = ((U64)timerp->mCallAverage * cur_frame + timerp->getFrameState().mCalls) / (cur_frame+1);
- }
- }
+std::vector<TimeBlock*>& TimeBlock::getChildren()
+{
+ return getTreeNode().mChildren;
}
// static
-void LLFastTimer::NamedTimer::resetFrame()
+void TimeBlock::logStats()
{
+ // get ready for next frame
if (sLog)
{ //output current frame counts to performance log
static S32 call_count = 0;
if (call_count % 100 == 0)
{
- LL_DEBUGS("FastTimers") << "countsPerSecond (32 bit): " << countsPerSecond() << LL_ENDL;
- LL_DEBUGS("FastTimers") << "get_clock_count (64 bit): " << get_clock_count() << llendl;
+ LL_DEBUGS("FastTimers") << "countsPerSecond: " << countsPerSecond() << LL_ENDL;
LL_DEBUGS("FastTimers") << "LLProcessorInfo().getCPUFrequency() " << LLProcessorInfo().getCPUFrequency() << LL_ENDL;
LL_DEBUGS("FastTimers") << "getCPUClockCount32() " << getCPUClockCount32() << LL_ENDL;
LL_DEBUGS("FastTimers") << "getCPUClockCount64() " << getCPUClockCount64() << LL_ENDL;
- LL_DEBUGS("FastTimers") << "elapsed sec " << ((F64)getCPUClockCount64())/((F64)LLProcessorInfo().getCPUFrequency()*1000000.0) << LL_ENDL;
+ LL_DEBUGS("FastTimers") << "elapsed sec " << ((F64)getCPUClockCount64()) / (LLUnit<LLUnits::Hertz, F64>(LLProcessorInfo().getCPUFrequency())) << LL_ENDL;
}
call_count++;
- F64 iclock_freq = 1000.0 / countsPerSecond(); // good place to calculate clock frequency
-
- F64 total_time = 0;
+ LLUnit<LLUnits::Seconds, F64> total_time(0);
LLSD sd;
{
- for (instance_iter it = beginInstances(); it != endInstances(); ++it)
+ for (LLInstanceTracker<TimeBlock>::instance_iter it = LLInstanceTracker<TimeBlock>::beginInstances(),
+ end_it = LLInstanceTracker<TimeBlock>::endInstances();
+ it != end_it;
+ ++it)
{
- NamedTimer& timer = *it;
- FrameState& info = timer.getFrameState();
- sd[timer.getName()]["Time"] = (LLSD::Real) (info.mSelfTimeCounter*iclock_freq);
- sd[timer.getName()]["Calls"] = (LLSD::Integer) info.mCalls;
+ TimeBlock& timer = *it;
+ LLTrace::PeriodicRecording& frame_recording = LLTrace::get_frame_recording();
+ sd[timer.getName()]["Time"] = (LLSD::Real) (frame_recording.getLastRecordingPeriod().getSum(timer).value());
+ sd[timer.getName()]["Calls"] = (LLSD::Integer) (frame_recording.getLastRecordingPeriod().getSum(timer.callCount()));
// computing total time here because getting the root timer's getCountHistory
// doesn't work correctly on the first frame
- total_time = total_time + info.mSelfTimeCounter * iclock_freq;
+ total_time += frame_recording.getLastRecordingPeriod().getSum(timer);
}
}
- sd["Total"]["Time"] = (LLSD::Real) total_time;
+ sd["Total"]["Time"] = (LLSD::Real) total_time.value();
sd["Total"]["Calls"] = (LLSD::Integer) 1;
{
@@ -469,162 +347,44 @@ void LLFastTimer::NamedTimer::resetFrame()
}
}
- // reset for next frame
- for (instance_iter it = beginInstances(); it != endInstances(); ++it)
- {
- NamedTimer& timer = *it;
-
- FrameState& info = timer.getFrameState();
- info.mSelfTimeCounter = 0;
- info.mCalls = 0;
- info.mLastCaller = NULL;
- info.mMoveUpTree = false;
- // update parent pointer in timer state struct
- if (timer.mParent)
- {
- info.mParent = &timer.mParent->getFrameState();
- }
- }
-}
-
-//static
-void LLFastTimer::NamedTimer::reset()
-{
- resetFrame(); // reset frame data
-
- // walk up stack of active timers and reset start times to current time
- // effectively zeroing out any accumulated time
- U32 cur_time = getCPUClockCount32();
-
- // root defined by parent pointing to self
- CurTimerData* cur_data = &sCurTimerData;
- LLFastTimer* cur_timer = cur_data->mCurTimer;
- while(cur_timer && cur_timer->mLastTimerData.mCurTimer != cur_timer)
- {
- cur_timer->mStartTime = cur_time;
- cur_data->mChildTime = 0;
-
- cur_data = &cur_timer->mLastTimerData;
- cur_timer = cur_data->mCurTimer;
- }
-
- // reset all history
- {
- for (instance_iter it = beginInstances(); it != endInstances(); ++it)
- {
- NamedTimer& timer = *it;
- if (&timer != NamedTimerFactory::instance().getRootTimer())
- {
- timer.setParent(NamedTimerFactory::instance().getRootTimer());
- }
-
- timer.mCountAverage = 0;
- timer.mCallAverage = 0;
- memset(timer.mCountHistory, 0, sizeof(U32) * HISTORY_NUM);
- memset(timer.mCallHistory, 0, sizeof(U32) * HISTORY_NUM);
- }
- }
-
- sLastFrameIndex = 0;
- sCurFrameIndex = 0;
-}
-
-U32 LLFastTimer::NamedTimer::getHistoricalCount(S32 history_index) const
-{
- S32 history_idx = (getLastFrameIndex() + history_index) % LLFastTimer::NamedTimer::HISTORY_NUM;
- return mCountHistory[history_idx];
-}
-
-U32 LLFastTimer::NamedTimer::getHistoricalCalls(S32 history_index ) const
-{
- S32 history_idx = (getLastFrameIndex() + history_index) % LLFastTimer::NamedTimer::HISTORY_NUM;
- return mCallHistory[history_idx];
-}
-
-LLFastTimer::FrameState& LLFastTimer::NamedTimer::getFrameState() const
-{
- return *mFrameState;
-}
-
-std::vector<LLFastTimer::NamedTimer*>::const_iterator LLFastTimer::NamedTimer::beginChildren()
-{
- return mChildren.begin();
-}
-
-std::vector<LLFastTimer::NamedTimer*>::const_iterator LLFastTimer::NamedTimer::endChildren()
-{
- return mChildren.end();
-}
-
-std::vector<LLFastTimer::NamedTimer*>& LLFastTimer::NamedTimer::getChildren()
-{
- return mChildren;
-}
-
-//static
-void LLFastTimer::nextFrame()
-{
- countsPerSecond(); // good place to calculate clock frequency
- U64 frame_time = getCPUClockCount64();
- if ((frame_time - sLastFrameTime) >> 8 > 0xffffffff)
- {
- llinfos << "Slow frame, fast timers inaccurate" << llendl;
- }
-
- if (!sPauseHistory)
- {
- NamedTimer::processTimes();
- sLastFrameIndex = sCurFrameIndex++;
- }
-
- // get ready for next frame
- NamedTimer::resetFrame();
- sLastFrameTime = frame_time;
}
//static
-void LLFastTimer::dumpCurTimes()
+void TimeBlock::dumpCurTimes()
{
- // accumulate timings, etc.
- NamedTimer::processTimes();
-
- F64 clock_freq = (F64)countsPerSecond();
- F64 iclock_freq = 1000.0 / clock_freq; // clock_ticks -> milliseconds
+ LLTrace::PeriodicRecording& frame_recording = LLTrace::get_frame_recording();
+ LLTrace::Recording& last_frame_recording = frame_recording.getLastRecordingPeriod();
// walk over timers in depth order and output timings
- for(timer_tree_dfs_iterator_t it = begin_timer_tree(*NamedTimerFactory::instance().getRootTimer());
+ for(timer_tree_dfs_iterator_t it = begin_timer_tree(TimeBlock::getRootTimeBlock());
it != end_timer_tree();
++it)
{
- NamedTimer* timerp = (*it);
- F64 total_time_ms = ((F64)timerp->getHistoricalCount(0) * iclock_freq);
+ TimeBlock* timerp = (*it);
+ LLUnit<LLUnits::Seconds, F64> total_time_ms = last_frame_recording.getSum(*timerp);
+ U32 num_calls = last_frame_recording.getSum(timerp->callCount());
+
// Don't bother with really brief times, keep output concise
if (total_time_ms < 0.1) continue;
std::ostringstream out_str;
- for (S32 i = 0; i < timerp->getDepth(); i++)
+ TimeBlock* parent_timerp = timerp;
+ while(parent_timerp && parent_timerp != parent_timerp->getParent())
{
out_str << "\t";
+ parent_timerp = parent_timerp->getParent();
}
-
out_str << timerp->getName() << " "
- << std::setprecision(3) << total_time_ms << " ms, "
- << timerp->getHistoricalCalls(0) << " calls";
+ << std::setprecision(3) << total_time_ms.as<LLUnits::Milliseconds>().value() << " ms, "
+ << num_calls << " calls";
llinfos << out_str.str() << llendl;
}
}
//static
-void LLFastTimer::reset()
-{
- NamedTimer::reset();
-}
-
-
-//static
-void LLFastTimer::writeLog(std::ostream& os)
+void TimeBlock::writeLog(std::ostream& os)
{
while (!sLogQueue.empty())
{
@@ -635,22 +395,59 @@ void LLFastTimer::writeLog(std::ostream& os)
}
}
-//static
-const LLFastTimer::NamedTimer* LLFastTimer::getTimerByName(const std::string& name)
+//////////////////////////////////////////////////////////////////////////////////////////////////////////////////
+// TimeBlockAccumulator
+//////////////////////////////////////////////////////////////////////////////////////////////////////////////////
+
+TimeBlockAccumulator::TimeBlockAccumulator()
+: mTotalTimeCounter(0),
+ mSelfTimeCounter(0),
+ mStartTotalTimeCounter(0),
+ mCalls(0),
+ mLastCaller(NULL),
+ mActiveCount(0),
+ mMoveUpTree(false),
+ mParent(NULL)
+{}
+
+void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other )
{
- return NamedTimerFactory::instance().getTimerByName(name);
+ mTotalTimeCounter += other.mTotalTimeCounter - other.mStartTotalTimeCounter;
+ mSelfTimeCounter += other.mSelfTimeCounter;
+ mCalls += other.mCalls;
+ mLastCaller = other.mLastCaller;
+ mActiveCount = other.mActiveCount;
+ mMoveUpTree = other.mMoveUpTree;
+ mParent = other.mParent;
}
-LLFastTimer::LLFastTimer(LLFastTimer::FrameState* state)
-: mFrameState(state)
+void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other )
{
- U32 start_time = getCPUClockCount32();
- mStartTime = start_time;
- mFrameState->mActiveCount++;
- LLFastTimer::sCurTimerData.mCurTimer = this;
- LLFastTimer::sCurTimerData.mFrameState = mFrameState;
- LLFastTimer::sCurTimerData.mChildTime = 0;
- mLastTimerData = LLFastTimer::sCurTimerData;
+ mCalls = 0;
+ mSelfTimeCounter = 0;
+
+ if (other)
+ {
+ mStartTotalTimeCounter = other->mTotalTimeCounter;
+ mTotalTimeCounter = mStartTotalTimeCounter;
+
+ mLastCaller = other->mLastCaller;
+ mActiveCount = other->mActiveCount;
+ mMoveUpTree = other->mMoveUpTree;
+ mParent = other->mParent;
+ }
+ else
+{
+ mStartTotalTimeCounter = mTotalTimeCounter;
+ }
+}
+
+LLUnit<LLUnits::Seconds, F64> BlockTimer::getElapsedTime()
+{
+ U64 total_time = TimeBlock::getCPUClockCount64() - mStartTime;
+
+ return (F64)total_time / (F64)TimeBlock::countsPerSecond();
}
+} // namespace LLTrace