From 62fcbb063a191fa4789145c3937e7bef6ce544bd Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Wed, 5 Sep 2012 18:49:28 -0700 Subject: SH-3275 WIP Run viewer metrics for object update messages first pass at LLTrace framework --- indra/llcommon/llfasttimer.cpp | 12 +++++++----- 1 file changed, 7 insertions(+), 5 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 6970c29092..939e332c3b 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -216,7 +216,7 @@ LLFastTimer::NamedTimer::NamedTimer(const std::string& name) : mName(name), mCollapsed(true), mParent(NULL), - mTotalTimeCounter(0), + mTreeTimeCounter(0), mCountAverage(0), mCallAverage(0), mNeedsSorting(false), @@ -389,6 +389,8 @@ void LLFastTimer::NamedTimer::accumulateTimings() U32 self_time_delta = cumulative_time_delta - cur_data->mChildTime; cur_data->mChildTime = 0; cur_timer->mFrameState->mSelfTimeCounter += self_time_delta; + cur_timer->mFrameState->mTotalTimeCounter += cumulative_time_delta; + cur_timer->mStartTime = cur_time; cur_data = &cur_timer->mLastTimerData; @@ -403,10 +405,10 @@ void LLFastTimer::NamedTimer::accumulateTimings() ++it) { NamedTimer* timerp = (*it); - timerp->mTotalTimeCounter = timerp->getFrameState().mSelfTimeCounter; + timerp->mTreeTimeCounter = timerp->getFrameState().mSelfTimeCounter; for (child_const_iter child_it = timerp->beginChildren(); child_it != timerp->endChildren(); ++child_it) { - timerp->mTotalTimeCounter += (*child_it)->mTotalTimeCounter; + timerp->mTreeTimeCounter += (*child_it)->mTreeTimeCounter; } S32 cur_frame = sCurFrameIndex; @@ -415,8 +417,8 @@ void LLFastTimer::NamedTimer::accumulateTimings() // update timer history int hidx = cur_frame % HISTORY_NUM; - timerp->mCountHistory[hidx] = timerp->mTotalTimeCounter; - timerp->mCountAverage = ((U64)timerp->mCountAverage * cur_frame + timerp->mTotalTimeCounter) / (cur_frame+1); + timerp->mCountHistory[hidx] = timerp->mTreeTimeCounter; + timerp->mCountAverage = ((U64)timerp->mCountAverage * cur_frame + timerp->mTreeTimeCounter) / (cur_frame+1); timerp->mCallHistory[hidx] = timerp->getFrameState().mCalls; timerp->mCallAverage = ((U64)timerp->mCallAverage * cur_frame + timerp->getFrameState().mCalls) / (cur_frame+1); } -- cgit v1.2.3 From 6814906fec95aeb90dbc99605f74f241a72af12b Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Wed, 5 Sep 2012 18:54:26 -0700 Subject: SH-3275 WIP Run viewer metrics for object update messages build fix --- indra/llcommon/llfasttimer.cpp | 26 +++++++++++++------------- 1 file changed, 13 insertions(+), 13 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 939e332c3b..0abaf73063 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -388,8 +388,8 @@ void LLFastTimer::NamedTimer::accumulateTimings() 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; - cur_timer->mFrameState->mTotalTimeCounter += cumulative_time_delta; + cur_data->mFrameState->mSelfTimeCounter += self_time_delta; + cur_data->mFrameState->mTotalTimeCounter += cumulative_time_delta; cur_timer->mStartTime = cur_time; @@ -643,16 +643,16 @@ const LLFastTimer::NamedTimer* LLFastTimer::getTimerByName(const std::string& na return NamedTimerFactory::instance().getTimerByName(name); } -LLFastTimer::LLFastTimer(LLFastTimer::FrameState* state) -: mFrameState(state) -{ - U32 start_time = getCPUClockCount32(); - mStartTime = start_time; - mFrameState->mActiveCount++; - LLFastTimer::sCurTimerData.mCurTimer = this; - LLFastTimer::sCurTimerData.mFrameState = mFrameState; - LLFastTimer::sCurTimerData.mChildTime = 0; - mLastTimerData = LLFastTimer::sCurTimerData; -} +//LLFastTimer::LLFastTimer(LLFastTimer::FrameState* state) +//: mFrameState(state) +//{ +// U32 start_time = getCPUClockCount32(); +// mStartTime = start_time; +// mFrameState->mActiveCount++; +// LLFastTimer::sCurTimerData.mCurTimer = this; +// LLFastTimer::sCurTimerData.mFrameState = mFrameState; +// LLFastTimer::sCurTimerData.mChildTime = 0; +// mLastTimerData = LLFastTimer::sCurTimerData; +//} -- cgit v1.2.3 From 860ff2f7e2a7fe932dfb7c148f0dbc0067018038 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Wed, 7 Nov 2012 00:38:21 -0800 Subject: SH-3499 WIP Ensure asset stats output is correct fixed trace data gathering and routing from background thread simplified slave->master thread communication (eliminated redundant recording and proxy object) improved performance of fast timer data gathering (slow iterators) --- indra/llcommon/llfasttimer.cpp | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 0abaf73063..4f67004773 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -319,7 +319,7 @@ void LLFastTimer::NamedTimer::buildHierarchy() // set up initial tree { - for (instance_iter it = beginInstances(); it != endInstances(); ++it) + for (instance_iter it = beginInstances(), end_it = endInstances(); it != end_it; ++it) { NamedTimer& timer = *it; if (&timer == NamedTimerFactory::instance().getRootTimer()) continue; @@ -449,7 +449,7 @@ void LLFastTimer::NamedTimer::resetFrame() LLSD sd; { - for (instance_iter it = beginInstances(); it != endInstances(); ++it) + for (instance_iter it = beginInstances(), end_it = endInstances(); it != end_it; ++it) { NamedTimer& timer = *it; FrameState& info = timer.getFrameState(); @@ -472,7 +472,7 @@ void LLFastTimer::NamedTimer::resetFrame() } // reset for next frame - for (instance_iter it = beginInstances(); it != endInstances(); ++it) + for (instance_iter it = beginInstances(), end_it = endInstances(); it != end_it; ++it) { NamedTimer& timer = *it; @@ -512,7 +512,7 @@ void LLFastTimer::NamedTimer::reset() // reset all history { - for (instance_iter it = beginInstances(); it != endInstances(); ++it) + for (instance_iter it = beginInstances(), end_it = endInstances(); it != end_it; ++it) { NamedTimer& timer = *it; if (&timer != NamedTimerFactory::instance().getRootTimer()) -- cgit v1.2.3 From a3e3e8b4ccd96e98da73acf1c584bbfa5a8b2b56 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Mon, 12 Nov 2012 19:08:14 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system simplified llfasttimer code down to 2 classes llunit unit conversion now done in floating point or 64 bit integer precision, depending on source type --- indra/llcommon/llfasttimer.cpp | 270 +++++++++++++---------------------------- 1 file changed, 85 insertions(+), 185 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 4f67004773..c4839fed77 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -32,6 +32,7 @@ #include "llsingleton.h" #include "lltreeiterators.h" #include "llsdserialize.h" +#include "llunit.h" #include @@ -73,13 +74,13 @@ U64 LLFastTimer::sClockResolution = 1000000; // Microsecond resolution // FIXME: move these declarations to the relevant modules // helper functions -typedef LLTreeDFSPostIter timer_tree_bottom_up_iterator_t; +typedef LLTreeDFSPostIter 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(LLFastTimer::DeclareTimer& 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(&LLFastTimer::DeclareTimer::beginChildren), _1), + boost::bind(boost::mem_fn(&LLFastTimer::DeclareTimer::endChildren), _1)); } static timer_tree_bottom_up_iterator_t end_timer_tree_bottom_up() @@ -87,14 +88,14 @@ static timer_tree_bottom_up_iterator_t end_timer_tree_bottom_up() return timer_tree_bottom_up_iterator_t(); } -typedef LLTreeDFSIter timer_tree_dfs_iterator_t; +typedef LLTreeDFSIter 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(LLFastTimer::DeclareTimer& 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(&LLFastTimer::DeclareTimer::beginChildren), _1), + boost::bind(boost::mem_fn(&LLFastTimer::DeclareTimer::endChildren), _1)); } static timer_tree_dfs_iterator_t end_timer_tree() @@ -102,75 +103,12 @@ 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 +LLFastTimer::DeclareTimer& LLFastTimer::DeclareTimer::getRootTimer() { -public: - NamedTimerFactory() - : mTimerRoot(NULL) - {} - - /*virtual */ void initSingleton() - { - mTimerRoot = new LLFastTimer::NamedTimer("root"); - mRootFrameState.setNamedTimer(mTimerRoot); - mTimerRoot->setFrameState(&mRootFrameState); - mTimerRoot->mParent = mTimerRoot; - mTimerRoot->setCollapsed(false); - mRootFrameState.mParent = &mRootFrameState; - } - - ~NamedTimerFactory() - { - std::for_each(mTimers.begin(), mTimers.end(), DeletePairedPointer()); - - delete mTimerRoot; - } - - LLFastTimer::NamedTimer& createNamedTimer(const std::string& name, LLFastTimer::FrameState* state) - { - LLFastTimer::NamedTimer* timer = new LLFastTimer::NamedTimer(name); - timer->setFrameState(state); - timer->setParent(mTimerRoot); - mTimers.insert(std::make_pair(name, timer)); - - return *timer; - } - - 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; - } - - LLFastTimer::NamedTimer* getRootTimer() { return mTimerRoot; } - - typedef std::multimap 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)) -{ - mTimer.setCollapsed(!open); + static DeclareTimer root_timer("root", true, NULL); + return root_timer; } -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__)) @@ -183,7 +121,7 @@ U64 LLFastTimer::countsPerSecond() // counts per second for the *32-bit* timer { #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 sCPUClockFrequency = LLProcessorInfo().getCPUFrequency(); // we drop the low-order byte in our timers, so report a lower frequency #else @@ -206,49 +144,44 @@ LLFastTimer::FrameState::FrameState() : mActiveCount(0), mCalls(0), mSelfTimeCounter(0), - mParent(NULL), mLastCaller(NULL), mMoveUpTree(false) {} -LLFastTimer::NamedTimer::NamedTimer(const std::string& name) +LLFastTimer::DeclareTimer::DeclareTimer(const std::string& name, bool open, DeclareTimer* parent) : mName(name), mCollapsed(true), mParent(NULL), mTreeTimeCounter(0), mCountAverage(0), mCallAverage(0), - mNeedsSorting(false), - mFrameState(NULL) + mNeedsSorting(false) { + setCollapsed(!open); + + if (parent) + { + setParent(parent); + } + else + { + mParent = this; + } + 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() +LLFastTimer::DeclareTimer::~DeclareTimer() { delete[] mCountHistory; delete[] mCallHistory; } -std::string LLFastTimer::NamedTimer::getToolTip(S32 history_idx) -{ - 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)); - } -} - -void LLFastTimer::NamedTimer::setParent(NamedTimer* parent) +void LLFastTimer::DeclareTimer::setParent(DeclareTimer* parent) { llassert_always(parent != this); llassert_always(parent != NULL); @@ -264,8 +197,8 @@ void LLFastTimer::NamedTimer::setParent(NamedTimer* parent) // subtract average timing from previous parent mParent->mCountAverage -= mCountAverage; - std::vector& children = mParent->getChildren(); - std::vector::iterator found_it = std::find(children.begin(), children.end(), this); + std::vector& children = mParent->getChildren(); + std::vector::iterator found_it = std::find(children.begin(), children.end(), this); if (found_it != children.end()) { children.erase(found_it); @@ -275,16 +208,15 @@ void LLFastTimer::NamedTimer::setParent(NamedTimer* parent) mParent = parent; if (parent) { - getFrameState().mParent = &parent->getFrameState(); parent->getChildren().push_back(this); parent->mNeedsSorting = true; } } -S32 LLFastTimer::NamedTimer::getDepth() +S32 LLFastTimer::DeclareTimer::getDepth() { S32 depth = 0; - NamedTimer* timerp = mParent; + DeclareTimer* timerp = mParent; while(timerp) { depth++; @@ -295,7 +227,7 @@ S32 LLFastTimer::NamedTimer::getDepth() } // static -void LLFastTimer::NamedTimer::processTimes() +void LLFastTimer::DeclareTimer::processTimes() { if (sCurFrameIndex < 0) return; @@ -306,14 +238,14 @@ void LLFastTimer::NamedTimer::processTimes() // sort child timers by name struct SortTimerByName { - bool operator()(const LLFastTimer::NamedTimer* i1, const LLFastTimer::NamedTimer* i2) + bool operator()(const LLFastTimer::DeclareTimer* i1, const LLFastTimer::DeclareTimer* i2) { return i1->getName() < i2->getName(); } }; //static -void LLFastTimer::NamedTimer::buildHierarchy() +void LLFastTimer::DeclareTimer::buildHierarchy() { if (sCurFrameIndex < 0 ) return; @@ -321,16 +253,16 @@ void LLFastTimer::NamedTimer::buildHierarchy() { for (instance_iter it = beginInstances(), end_it = endInstances(); it != end_it; ++it) { - NamedTimer& timer = *it; - if (&timer == NamedTimerFactory::instance().getRootTimer()) continue; + DeclareTimer& timer = *it; + if (&timer == &DeclareTimer::getRootTimer()) 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.mLastCaller && timer.mParent == &DeclareTimer::getRootTimer()) { - timer.setParent(timer.getFrameState().mLastCaller->mTimer); + timer.setParent(timer.mLastCaller); // no need to push up tree on first use, flag can be set spuriously - timer.getFrameState().mMoveUpTree = false; + timer.mMoveUpTree = false; } } } @@ -338,22 +270,22 @@ void LLFastTimer::NamedTimer::buildHierarchy() // bump timers up tree if they've 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(DeclareTimer::getRootTimer()); it != end_timer_tree_bottom_up(); ++it) { - NamedTimer* timerp = *it; + DeclareTimer* timerp = *it; // skip root timer - if (timerp == NamedTimerFactory::instance().getRootTimer()) continue; + if (timerp == &DeclareTimer::getRootTimer()) continue; - if (timerp->getFrameState().mMoveUpTree) + if (timerp->mMoveUpTree) { // since ancestors have already been visited, reparenting 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; + timerp->mMoveUpTree = false; // don't bubble up any ancestors until descendants are done bubbling up it.skipAncestors(); @@ -361,11 +293,11 @@ void LLFastTimer::NamedTimer::buildHierarchy() } // sort timers by time last called, so call graph makes sense - for(timer_tree_dfs_iterator_t it = begin_timer_tree(*NamedTimerFactory::instance().getRootTimer()); + for(timer_tree_dfs_iterator_t it = begin_timer_tree(DeclareTimer::getRootTimer()); it != end_timer_tree(); ++it) { - NamedTimer* timerp = (*it); + DeclareTimer* timerp = (*it); if (timerp->mNeedsSorting) { std::sort(timerp->getChildren().begin(), timerp->getChildren().end(), SortTimerByName()); @@ -375,7 +307,7 @@ void LLFastTimer::NamedTimer::buildHierarchy() } //static -void LLFastTimer::NamedTimer::accumulateTimings() +void LLFastTimer::DeclareTimer::accumulateTimings() { U32 cur_time = getCPUClockCount32(); @@ -388,8 +320,8 @@ void LLFastTimer::NamedTimer::accumulateTimings() U32 cumulative_time_delta = cur_time - cur_timer->mStartTime; U32 self_time_delta = cumulative_time_delta - cur_data->mChildTime; cur_data->mChildTime = 0; - cur_data->mFrameState->mSelfTimeCounter += self_time_delta; - cur_data->mFrameState->mTotalTimeCounter += cumulative_time_delta; + cur_data->mTimerData->mSelfTimeCounter += self_time_delta; + cur_data->mTimerData->mTotalTimeCounter += cumulative_time_delta; cur_timer->mStartTime = cur_time; @@ -400,12 +332,12 @@ void LLFastTimer::NamedTimer::accumulateTimings() } // 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()); + for(timer_tree_bottom_up_iterator_t it = begin_timer_tree_bottom_up(DeclareTimer::getRootTimer()); it != end_timer_tree_bottom_up(); ++it) { - NamedTimer* timerp = (*it); - timerp->mTreeTimeCounter = timerp->getFrameState().mSelfTimeCounter; + DeclareTimer* timerp = (*it); + timerp->mTreeTimeCounter = timerp->mSelfTimeCounter; for (child_const_iter child_it = timerp->beginChildren(); child_it != timerp->endChildren(); ++child_it) { timerp->mTreeTimeCounter += (*child_it)->mTreeTimeCounter; @@ -418,15 +350,15 @@ void LLFastTimer::NamedTimer::accumulateTimings() int hidx = cur_frame % HISTORY_NUM; timerp->mCountHistory[hidx] = timerp->mTreeTimeCounter; - timerp->mCountAverage = ((U64)timerp->mCountAverage * cur_frame + timerp->mTreeTimeCounter) / (cur_frame+1); - timerp->mCallHistory[hidx] = timerp->getFrameState().mCalls; - timerp->mCallAverage = ((U64)timerp->mCallAverage * cur_frame + timerp->getFrameState().mCalls) / (cur_frame+1); + timerp->mCountAverage = ((U64)timerp->mCountAverage * cur_frame + timerp->mTreeTimeCounter) / (cur_frame+1); + timerp->mCallHistory[hidx] = timerp->mCalls; + timerp->mCallAverage = ((U64)timerp->mCallAverage * cur_frame + timerp->mCalls) / (cur_frame+1); } } } // static -void LLFastTimer::NamedTimer::resetFrame() +void LLFastTimer::DeclareTimer::resetFrame() { if (sLog) { //output current frame counts to performance log @@ -435,11 +367,11 @@ void LLFastTimer::NamedTimer::resetFrame() 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") << "get_clock_count (64 bit): " << get_clock_count() << 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(LLProcessorInfo().getCPUFrequency())) << LL_ENDL; } call_count++; @@ -451,14 +383,13 @@ void LLFastTimer::NamedTimer::resetFrame() { for (instance_iter it = beginInstances(), end_it = 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; + DeclareTimer& timer = *it; + sd[timer.getName()]["Time"] = (LLSD::Real) (timer.mSelfTimeCounter*iclock_freq); + sd[timer.getName()]["Calls"] = (LLSD::Integer) timer.mCalls; // 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 = total_time + timer.mSelfTimeCounter * iclock_freq; } } @@ -474,23 +405,16 @@ void LLFastTimer::NamedTimer::resetFrame() // reset for next frame for (instance_iter it = beginInstances(), end_it = endInstances(); it != end_it; ++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(); - } + DeclareTimer& timer = *it; + timer.mSelfTimeCounter = 0; + timer.mCalls = 0; + timer.mLastCaller = NULL; + timer.mMoveUpTree = false; } } //static -void LLFastTimer::NamedTimer::reset() +void LLFastTimer::DeclareTimer::reset() { resetFrame(); // reset frame data @@ -514,10 +438,10 @@ void LLFastTimer::NamedTimer::reset() { for (instance_iter it = beginInstances(), end_it = endInstances(); it != end_it; ++it) { - NamedTimer& timer = *it; - if (&timer != NamedTimerFactory::instance().getRootTimer()) + DeclareTimer& timer = *it; + if (&timer != &DeclareTimer::getRootTimer()) { - timer.setParent(NamedTimerFactory::instance().getRootTimer()); + timer.setParent(&DeclareTimer::getRootTimer()); } timer.mCountAverage = 0; @@ -531,34 +455,29 @@ void LLFastTimer::NamedTimer::reset() sCurFrameIndex = 0; } -U32 LLFastTimer::NamedTimer::getHistoricalCount(S32 history_index) const +U32 LLFastTimer::DeclareTimer::getHistoricalCount(S32 history_index) const { - S32 history_idx = (getLastFrameIndex() + history_index) % LLFastTimer::NamedTimer::HISTORY_NUM; + S32 history_idx = (getLastFrameIndex() + history_index) % LLFastTimer::DeclareTimer::HISTORY_NUM; return mCountHistory[history_idx]; } -U32 LLFastTimer::NamedTimer::getHistoricalCalls(S32 history_index ) const +U32 LLFastTimer::DeclareTimer::getHistoricalCalls(S32 history_index ) const { - S32 history_idx = (getLastFrameIndex() + history_index) % LLFastTimer::NamedTimer::HISTORY_NUM; + S32 history_idx = (getLastFrameIndex() + history_index) % LLFastTimer::DeclareTimer::HISTORY_NUM; return mCallHistory[history_idx]; } -LLFastTimer::FrameState& LLFastTimer::NamedTimer::getFrameState() const -{ - return *mFrameState; -} - -std::vector::const_iterator LLFastTimer::NamedTimer::beginChildren() +std::vector::const_iterator LLFastTimer::DeclareTimer::beginChildren() { return mChildren.begin(); } -std::vector::const_iterator LLFastTimer::NamedTimer::endChildren() +std::vector::const_iterator LLFastTimer::DeclareTimer::endChildren() { return mChildren.end(); } -std::vector& LLFastTimer::NamedTimer::getChildren() +std::vector& LLFastTimer::DeclareTimer::getChildren() { return mChildren; } @@ -575,12 +494,12 @@ void LLFastTimer::nextFrame() if (!sPauseHistory) { - NamedTimer::processTimes(); + DeclareTimer::processTimes(); sLastFrameIndex = sCurFrameIndex++; } // get ready for next frame - NamedTimer::resetFrame(); + DeclareTimer::resetFrame(); sLastFrameTime = frame_time; } @@ -588,17 +507,17 @@ void LLFastTimer::nextFrame() void LLFastTimer::dumpCurTimes() { // accumulate timings, etc. - NamedTimer::processTimes(); + DeclareTimer::processTimes(); F64 clock_freq = (F64)countsPerSecond(); F64 iclock_freq = 1000.0 / clock_freq; // clock_ticks -> milliseconds // 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(DeclareTimer::getRootTimer()); it != end_timer_tree(); ++it) { - NamedTimer* timerp = (*it); + DeclareTimer* timerp = (*it); F64 total_time_ms = ((F64)timerp->getHistoricalCount(0) * iclock_freq); // Don't bother with really brief times, keep output concise if (total_time_ms < 0.1) continue; @@ -621,7 +540,7 @@ void LLFastTimer::dumpCurTimes() //static void LLFastTimer::reset() { - NamedTimer::reset(); + DeclareTimer::reset(); } @@ -637,22 +556,3 @@ void LLFastTimer::writeLog(std::ostream& os) } } -//static -const LLFastTimer::NamedTimer* LLFastTimer::getTimerByName(const std::string& name) -{ - return NamedTimerFactory::instance().getTimerByName(name); -} - -//LLFastTimer::LLFastTimer(LLFastTimer::FrameState* state) -//: mFrameState(state) -//{ -// U32 start_time = getCPUClockCount32(); -// mStartTime = start_time; -// mFrameState->mActiveCount++; -// LLFastTimer::sCurTimerData.mCurTimer = this; -// LLFastTimer::sCurTimerData.mFrameState = mFrameState; -// LLFastTimer::sCurTimerData.mChildTime = 0; -// mLastTimerData = LLFastTimer::sCurTimerData; -//} - - -- cgit v1.2.3 From c76ed72c609b80b08df6cebd68274c9da6d3de2c Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Mon, 12 Nov 2012 19:12:20 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system removed remnants of LLFastTimer::FrameState --- indra/llcommon/llfasttimer.cpp | 16 ++++++---------- 1 file changed, 6 insertions(+), 10 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index c4839fed77..66452fd02a 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -140,15 +140,6 @@ U64 LLFastTimer::countsPerSecond() // counts per second for the *32-bit* timer } #endif -LLFastTimer::FrameState::FrameState() -: mActiveCount(0), - mCalls(0), - mSelfTimeCounter(0), - mLastCaller(NULL), - mMoveUpTree(false) -{} - - LLFastTimer::DeclareTimer::DeclareTimer(const std::string& name, bool open, DeclareTimer* parent) : mName(name), mCollapsed(true), @@ -156,7 +147,12 @@ LLFastTimer::DeclareTimer::DeclareTimer(const std::string& name, bool open, Decl mTreeTimeCounter(0), mCountAverage(0), mCallAverage(0), - mNeedsSorting(false) + mNeedsSorting(false), + mActiveCount(0), + mCalls(0), + mSelfTimeCounter(0), + mLastCaller(NULL), + mMoveUpTree(false) { setCollapsed(!open); -- cgit v1.2.3 From 67ec47e6da389661934ed2ddfa55ca58455fa7e5 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Tue, 13 Nov 2012 17:10:10 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system moving fast timers into lltrace namespace and accumulation system --- indra/llcommon/llfasttimer.cpp | 186 +++++++++++++++++++++++------------------ 1 file changed, 104 insertions(+), 82 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 66452fd02a..cced0bdfa9 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -33,8 +33,10 @@ #include "lltreeiterators.h" #include "llsdserialize.h" #include "llunit.h" +#include "llsd.h" #include +#include #if LL_WINDOWS @@ -50,37 +52,40 @@ #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 LLFastTimer::sLogQueue; +S32 Time::sCurFrameIndex = -1; +S32 Time::sLastFrameIndex = -1; +U64 Time::sLastFrameTime = Time::getCPUClockCount64(); +bool Time::sPauseHistory = 0; +bool Time::sResetHistory = 0; +LLThreadLocalPointer Time::sCurTimerData; +bool Time::sLog = FALSE; +std::string Time::sLogName = ""; +bool Time::sMetricLog = FALSE; +static LLMutex* sLogLock = NULL; +static std::queue sLogQueue; #if LL_LINUX || LL_SOLARIS -U64 LLFastTimer::sClockResolution = 1000000000; // Nanosecond resolution +U64 Time::sClockResolution = 1000000000; // Nanosecond resolution #else -U64 LLFastTimer::sClockResolution = 1000000; // Microsecond resolution +U64 Time::sClockResolution = 1000000; // Microsecond resolution #endif // FIXME: move these declarations to the relevant modules // helper functions -typedef LLTreeDFSPostIter timer_tree_bottom_up_iterator_t; +typedef LLTreeDFSPostIter timer_tree_bottom_up_iterator_t; -static timer_tree_bottom_up_iterator_t begin_timer_tree_bottom_up(LLFastTimer::DeclareTimer& id) +static timer_tree_bottom_up_iterator_t begin_timer_tree_bottom_up(BlockTimer& id) { return timer_tree_bottom_up_iterator_t(&id, - boost::bind(boost::mem_fn(&LLFastTimer::DeclareTimer::beginChildren), _1), - boost::bind(boost::mem_fn(&LLFastTimer::DeclareTimer::endChildren), _1)); + boost::bind(boost::mem_fn(&BlockTimer::beginChildren), _1), + boost::bind(boost::mem_fn(&BlockTimer::endChildren), _1)); } static timer_tree_bottom_up_iterator_t end_timer_tree_bottom_up() @@ -88,14 +93,14 @@ static timer_tree_bottom_up_iterator_t end_timer_tree_bottom_up() return timer_tree_bottom_up_iterator_t(); } -typedef LLTreeDFSIter timer_tree_dfs_iterator_t; +typedef LLTreeDFSIter timer_tree_dfs_iterator_t; -static timer_tree_dfs_iterator_t begin_timer_tree(LLFastTimer::DeclareTimer& id) +static timer_tree_dfs_iterator_t begin_timer_tree(BlockTimer& id) { return timer_tree_dfs_iterator_t(&id, - boost::bind(boost::mem_fn(&LLFastTimer::DeclareTimer::beginChildren), _1), - boost::bind(boost::mem_fn(&LLFastTimer::DeclareTimer::endChildren), _1)); + boost::bind(boost::mem_fn(&BlockTimer::beginChildren), _1), + boost::bind(boost::mem_fn(&BlockTimer::endChildren), _1)); } static timer_tree_dfs_iterator_t end_timer_tree() @@ -103,21 +108,21 @@ static timer_tree_dfs_iterator_t end_timer_tree() return timer_tree_dfs_iterator_t(); } -LLFastTimer::DeclareTimer& LLFastTimer::DeclareTimer::getRootTimer() +BlockTimer& BlockTimer::getRootTimer() { - static DeclareTimer root_timer("root", true, NULL); + static BlockTimer root_timer("root", true, NULL); return root_timer; } //static #if (LL_DARWIN || LL_LINUX || LL_SOLARIS) && !(defined(__i386__) || defined(__amd64__)) -U64 LLFastTimer::countsPerSecond() // counts per second for the *32-bit* timer +U64 Time::countsPerSecond() // counts per second for the *32-bit* timer { return sClockResolution >> 8; } #else // windows or x86-mac or x86-linux or x86-solaris -U64 LLFastTimer::countsPerSecond() // counts per second for the *32-bit* timer +U64 Time::countsPerSecond() // counts per second for the *32-bit* timer { #if LL_FASTTIMER_USE_RDTSC || !LL_WINDOWS //getCPUFrequency returns MHz and sCPUClockFrequency wants to be in Hz @@ -140,19 +145,14 @@ U64 LLFastTimer::countsPerSecond() // counts per second for the *32-bit* timer } #endif -LLFastTimer::DeclareTimer::DeclareTimer(const std::string& name, bool open, DeclareTimer* parent) -: mName(name), +BlockTimer::BlockTimer(const char* name, bool open, BlockTimer* parent) +: TraceType(name), mCollapsed(true), mParent(NULL), mTreeTimeCounter(0), mCountAverage(0), mCallAverage(0), - mNeedsSorting(false), - mActiveCount(0), - mCalls(0), - mSelfTimeCounter(0), - mLastCaller(NULL), - mMoveUpTree(false) + mNeedsSorting(false) { setCollapsed(!open); @@ -171,13 +171,13 @@ LLFastTimer::DeclareTimer::DeclareTimer(const std::string& name, bool open, Decl memset(mCallHistory, 0, sizeof(U32) * HISTORY_NUM); } -LLFastTimer::DeclareTimer::~DeclareTimer() +BlockTimer::~BlockTimer() { delete[] mCountHistory; delete[] mCallHistory; } -void LLFastTimer::DeclareTimer::setParent(DeclareTimer* parent) +void BlockTimer::setParent(BlockTimer* parent) { llassert_always(parent != this); llassert_always(parent != NULL); @@ -193,8 +193,8 @@ void LLFastTimer::DeclareTimer::setParent(DeclareTimer* parent) // subtract average timing from previous parent mParent->mCountAverage -= mCountAverage; - std::vector& children = mParent->getChildren(); - std::vector::iterator found_it = std::find(children.begin(), children.end(), this); + std::vector& children = mParent->getChildren(); + std::vector::iterator found_it = std::find(children.begin(), children.end(), this); if (found_it != children.end()) { children.erase(found_it); @@ -209,10 +209,10 @@ void LLFastTimer::DeclareTimer::setParent(DeclareTimer* parent) } } -S32 LLFastTimer::DeclareTimer::getDepth() +S32 BlockTimer::getDepth() { S32 depth = 0; - DeclareTimer* timerp = mParent; + BlockTimer* timerp = mParent; while(timerp) { depth++; @@ -223,9 +223,9 @@ S32 LLFastTimer::DeclareTimer::getDepth() } // static -void LLFastTimer::DeclareTimer::processTimes() +void BlockTimer::processTimes() { - if (sCurFrameIndex < 0) return; + if (Time::getCurFrameIndex() < 0) return; buildHierarchy(); accumulateTimings(); @@ -234,27 +234,27 @@ void LLFastTimer::DeclareTimer::processTimes() // sort child timers by name struct SortTimerByName { - bool operator()(const LLFastTimer::DeclareTimer* i1, const LLFastTimer::DeclareTimer* i2) + bool operator()(const BlockTimer* i1, const BlockTimer* i2) { return i1->getName() < i2->getName(); } }; //static -void LLFastTimer::DeclareTimer::buildHierarchy() +void BlockTimer::buildHierarchy() { - if (sCurFrameIndex < 0 ) return; + if (Time::getCurFrameIndex() < 0 ) return; // set up initial tree { - for (instance_iter it = beginInstances(), end_it = endInstances(); it != end_it; ++it) + for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), end_it = LLInstanceTracker::endInstances(); it != end_it; ++it) { - DeclareTimer& timer = *it; - if (&timer == &DeclareTimer::getRootTimer()) continue; + BlockTimer& timer = *it; + if (&timer == &BlockTimer::getRootTimer()) continue; // bootstrap tree construction by attaching to last timer to be on stack // when this timer was called - if (timer.mLastCaller && timer.mParent == &DeclareTimer::getRootTimer()) + if (timer.mLastCaller && timer.mParent == &BlockTimer::getRootTimer()) { timer.setParent(timer.mLastCaller); // no need to push up tree on first use, flag can be set spuriously @@ -266,13 +266,13 @@ void LLFastTimer::DeclareTimer::buildHierarchy() // bump timers up tree if they've 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(DeclareTimer::getRootTimer()); + for(timer_tree_bottom_up_iterator_t it = begin_timer_tree_bottom_up(BlockTimer::getRootTimer()); it != end_timer_tree_bottom_up(); ++it) { - DeclareTimer* timerp = *it; + BlockTimer* timerp = *it; // skip root timer - if (timerp == &DeclareTimer::getRootTimer()) continue; + if (timerp == &BlockTimer::getRootTimer()) continue; if (timerp->mMoveUpTree) { @@ -289,11 +289,11 @@ void LLFastTimer::DeclareTimer::buildHierarchy() } // sort timers by time last called, so call graph makes sense - for(timer_tree_dfs_iterator_t it = begin_timer_tree(DeclareTimer::getRootTimer()); + for(timer_tree_dfs_iterator_t it = begin_timer_tree(BlockTimer::getRootTimer()); it != end_timer_tree(); ++it) { - DeclareTimer* timerp = (*it); + BlockTimer* timerp = (*it); if (timerp->mNeedsSorting) { std::sort(timerp->getChildren().begin(), timerp->getChildren().end(), SortTimerByName()); @@ -303,12 +303,12 @@ void LLFastTimer::DeclareTimer::buildHierarchy() } //static -void LLFastTimer::DeclareTimer::accumulateTimings() +void BlockTimer::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; + Time* cur_timer = sCurTimerData.mCurTimer; // root defined by parent pointing to self CurTimerData* cur_data = &sCurTimerData; while(cur_timer && cur_timer->mLastTimerData.mCurTimer != cur_timer) @@ -328,11 +328,11 @@ void LLFastTimer::DeclareTimer::accumulateTimings() } // traverse tree in DFS post order, or bottom up - for(timer_tree_bottom_up_iterator_t it = begin_timer_tree_bottom_up(DeclareTimer::getRootTimer()); + for(timer_tree_bottom_up_iterator_t it = begin_timer_tree_bottom_up(BlockTimer::getRootTimer()); it != end_timer_tree_bottom_up(); ++it) { - DeclareTimer* timerp = (*it); + BlockTimer* timerp = (*it); timerp->mTreeTimeCounter = timerp->mSelfTimeCounter; for (child_const_iter child_it = timerp->beginChildren(); child_it != timerp->endChildren(); ++child_it) { @@ -354,7 +354,7 @@ void LLFastTimer::DeclareTimer::accumulateTimings() } // static -void LLFastTimer::DeclareTimer::resetFrame() +void BlockTimer::resetFrame() { if (sLog) { //output current frame counts to performance log @@ -379,7 +379,7 @@ void LLFastTimer::DeclareTimer::resetFrame() { for (instance_iter it = beginInstances(), end_it = endInstances(); it != end_it; ++it) { - DeclareTimer& timer = *it; + BlockTimer& timer = *it; sd[timer.getName()]["Time"] = (LLSD::Real) (timer.mSelfTimeCounter*iclock_freq); sd[timer.getName()]["Calls"] = (LLSD::Integer) timer.mCalls; @@ -401,7 +401,7 @@ void LLFastTimer::DeclareTimer::resetFrame() // reset for next frame for (instance_iter it = beginInstances(), end_it = endInstances(); it != end_it; ++it) { - DeclareTimer& timer = *it; + BlockTimer& timer = *it; timer.mSelfTimeCounter = 0; timer.mCalls = 0; timer.mLastCaller = NULL; @@ -410,7 +410,7 @@ void LLFastTimer::DeclareTimer::resetFrame() } //static -void LLFastTimer::DeclareTimer::reset() +void BlockTimer::reset() { resetFrame(); // reset frame data @@ -420,7 +420,7 @@ void LLFastTimer::DeclareTimer::reset() // root defined by parent pointing to self CurTimerData* cur_data = &sCurTimerData; - LLFastTimer* cur_timer = cur_data->mCurTimer; + Time* cur_timer = cur_data->mCurTimer; while(cur_timer && cur_timer->mLastTimerData.mCurTimer != cur_timer) { cur_timer->mStartTime = cur_time; @@ -434,10 +434,10 @@ void LLFastTimer::DeclareTimer::reset() { for (instance_iter it = beginInstances(), end_it = endInstances(); it != end_it; ++it) { - DeclareTimer& timer = *it; - if (&timer != &DeclareTimer::getRootTimer()) + BlockTimer& timer = *it; + if (&timer != &BlockTimer::getRootTimer()) { - timer.setParent(&DeclareTimer::getRootTimer()); + timer.setParent(&BlockTimer::getRootTimer()); } timer.mCountAverage = 0; @@ -451,35 +451,35 @@ void LLFastTimer::DeclareTimer::reset() sCurFrameIndex = 0; } -U32 LLFastTimer::DeclareTimer::getHistoricalCount(S32 history_index) const +U32 BlockTimer::getHistoricalCount(S32 history_index) const { - S32 history_idx = (getLastFrameIndex() + history_index) % LLFastTimer::DeclareTimer::HISTORY_NUM; + S32 history_idx = (getLastFrameIndex() + history_index) % BlockTimer::HISTORY_NUM; return mCountHistory[history_idx]; } -U32 LLFastTimer::DeclareTimer::getHistoricalCalls(S32 history_index ) const +U32 BlockTimer::getHistoricalCalls(S32 history_index ) const { - S32 history_idx = (getLastFrameIndex() + history_index) % LLFastTimer::DeclareTimer::HISTORY_NUM; + S32 history_idx = (getLastFrameIndex() + history_index) % BlockTimer::HISTORY_NUM; return mCallHistory[history_idx]; } -std::vector::const_iterator LLFastTimer::DeclareTimer::beginChildren() +std::vector::const_iterator BlockTimer::beginChildren() { return mChildren.begin(); } -std::vector::const_iterator LLFastTimer::DeclareTimer::endChildren() +std::vector::const_iterator BlockTimer::endChildren() { return mChildren.end(); } -std::vector& LLFastTimer::DeclareTimer::getChildren() +std::vector& BlockTimer::getChildren() { return mChildren; } //static -void LLFastTimer::nextFrame() +void Time::nextFrame() { countsPerSecond(); // good place to calculate clock frequency U64 frame_time = getCPUClockCount64(); @@ -490,30 +490,30 @@ void LLFastTimer::nextFrame() if (!sPauseHistory) { - DeclareTimer::processTimes(); + BlockTimer::processTimes(); sLastFrameIndex = sCurFrameIndex++; } // get ready for next frame - DeclareTimer::resetFrame(); + BlockTimer::resetFrame(); sLastFrameTime = frame_time; } //static -void LLFastTimer::dumpCurTimes() +void Time::dumpCurTimes() { // accumulate timings, etc. - DeclareTimer::processTimes(); + BlockTimer::processTimes(); F64 clock_freq = (F64)countsPerSecond(); F64 iclock_freq = 1000.0 / clock_freq; // clock_ticks -> milliseconds // walk over timers in depth order and output timings - for(timer_tree_dfs_iterator_t it = begin_timer_tree(DeclareTimer::getRootTimer()); + for(timer_tree_dfs_iterator_t it = begin_timer_tree(BlockTimer::getRootTimer()); it != end_timer_tree(); ++it) { - DeclareTimer* timerp = (*it); + BlockTimer* timerp = (*it); F64 total_time_ms = ((F64)timerp->getHistoricalCount(0) * iclock_freq); // Don't bother with really brief times, keep output concise if (total_time_ms < 0.1) continue; @@ -534,14 +534,14 @@ void LLFastTimer::dumpCurTimes() } //static -void LLFastTimer::reset() +void Time::reset() { - DeclareTimer::reset(); + BlockTimer::reset(); } //static -void LLFastTimer::writeLog(std::ostream& os) +void Time::writeLog(std::ostream& os) { while (!sLogQueue.empty()) { @@ -552,3 +552,25 @@ void LLFastTimer::writeLog(std::ostream& os) } } + +void LLTrace::TimerAccumulator::addSamples( const LLTrace::TimerAccumulator& other ) +{ + mSelfTimeCounter += other.mSelfTimeCounter; + mTotalTimeCounter += other.mTotalTimeCounter; + mCalls += other.mCalls; + if (!mLastCaller) + { + mLastCaller = other.mLastCaller; + } + + //mActiveCount stays the same; + mMoveUpTree |= other.mMoveUpTree; +} + +void LLTrace::TimerAccumulator::reset( const LLTrace::TimerAccumulator* other ) +{ + mTotalTimeCounter = 0; + mSelfTimeCounter = 0; + mCalls = 0; +} +} -- cgit v1.2.3 From 9d77e030d9a0d23cebce616631677459eec1612c Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Wed, 14 Nov 2012 23:52:27 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system cleaning up build moved most includes of windows.h to llwin32headers.h to disable min/max macros, etc streamlined Time class and consolidated functionality in BlockTimer class llfasttimer is no longer included via llstring.h, so had to add it manually in several places --- indra/llcommon/llfasttimer.cpp | 120 +++++++++++++++++++++++------------------ 1 file changed, 67 insertions(+), 53 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index cced0bdfa9..d007f76e5f 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -58,22 +58,22 @@ namespace LLTrace ////////////////////////////////////////////////////////////////////////////// // statics -S32 Time::sCurFrameIndex = -1; -S32 Time::sLastFrameIndex = -1; -U64 Time::sLastFrameTime = Time::getCPUClockCount64(); -bool Time::sPauseHistory = 0; -bool Time::sResetHistory = 0; -LLThreadLocalPointer Time::sCurTimerData; -bool Time::sLog = FALSE; -std::string Time::sLogName = ""; -bool Time::sMetricLog = FALSE; +S32 BlockTimer::sCurFrameIndex = -1; +S32 BlockTimer::sLastFrameIndex = -1; +U64 BlockTimer::sLastFrameTime = BlockTimer::getCPUClockCount64(); +bool BlockTimer::sPauseHistory = 0; +bool BlockTimer::sResetHistory = 0; +LLThreadLocalPointer BlockTimer::sCurTimerData; +bool BlockTimer::sLog = false; +std::string BlockTimer::sLogName = ""; +bool BlockTimer::sMetricLog = false; static LLMutex* sLogLock = NULL; static std::queue sLogQueue; #if LL_LINUX || LL_SOLARIS -U64 Time::sClockResolution = 1000000000; // Nanosecond resolution +U64 BlockTimer::sClockResolution = 1000000000; // Nanosecond resolution #else -U64 Time::sClockResolution = 1000000; // Microsecond resolution +U64 BlockTimer::sClockResolution = 1000000; // Microsecond resolution #endif // FIXME: move these declarations to the relevant modules @@ -114,15 +114,22 @@ BlockTimer& BlockTimer::getRootTimer() return root_timer; } +void BlockTimer::pushLog(LLSD log) +{ + LLMutexLock lock(sLogLock); + + sLogQueue.push(log); +} + //static #if (LL_DARWIN || LL_LINUX || LL_SOLARIS) && !(defined(__i386__) || defined(__amd64__)) -U64 Time::countsPerSecond() // counts per second for the *32-bit* timer +U64 BlockTimer::countsPerSecond() // counts per second for the *32-bit* timer { return sClockResolution >> 8; } #else // windows or x86-mac or x86-linux or x86-solaris -U64 Time::countsPerSecond() // counts per second for the *32-bit* timer +U64 BlockTimer::countsPerSecond() // counts per second for the *32-bit* timer { #if LL_FASTTIMER_USE_RDTSC || !LL_WINDOWS //getCPUFrequency returns MHz and sCPUClockFrequency wants to be in Hz @@ -225,7 +232,7 @@ S32 BlockTimer::getDepth() // static void BlockTimer::processTimes() { - if (Time::getCurFrameIndex() < 0) return; + if (getCurFrameIndex() < 0) return; buildHierarchy(); accumulateTimings(); @@ -243,7 +250,7 @@ struct SortTimerByName //static void BlockTimer::buildHierarchy() { - if (Time::getCurFrameIndex() < 0 ) return; + if (getCurFrameIndex() < 0 ) return; // set up initial tree { @@ -254,11 +261,11 @@ void BlockTimer::buildHierarchy() // bootstrap tree construction by attaching to last timer to be on stack // when this timer was called - if (timer.mLastCaller && timer.mParent == &BlockTimer::getRootTimer()) + if (timer.getPrimaryAccumulator().mLastCaller && timer.mParent == &BlockTimer::getRootTimer()) { - timer.setParent(timer.mLastCaller); + timer.setParent(timer.getPrimaryAccumulator().mLastCaller); // no need to push up tree on first use, flag can be set spuriously - timer.mMoveUpTree = false; + timer.getPrimaryAccumulator().mMoveUpTree = false; } } } @@ -274,14 +281,14 @@ void BlockTimer::buildHierarchy() // skip root timer if (timerp == &BlockTimer::getRootTimer()) continue; - if (timerp->mMoveUpTree) + if (timerp->getPrimaryAccumulator().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->mMoveUpTree = false; + timerp->getPrimaryAccumulator().mMoveUpTree = false; // don't bubble up any ancestors until descendants are done bubbling up it.skipAncestors(); @@ -308,21 +315,23 @@ void BlockTimer::accumulateTimings() U32 cur_time = getCPUClockCount32(); // walk up stack of active timers and accumulate current time while leaving timing structures active - Time* cur_timer = sCurTimerData.mCurTimer; + Time* cur_timer = sCurTimerData->mCurTimer; // root defined by parent pointing to self - CurTimerData* cur_data = &sCurTimerData; + CurTimerData* cur_data = sCurTimerData.get(); + TimerAccumulator& accumulator = sCurTimerData->mTimerData->getPrimaryAccumulator(); while(cur_timer && cur_timer->mLastTimerData.mCurTimer != 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_data->mTimerData->mSelfTimeCounter += self_time_delta; - cur_data->mTimerData->mTotalTimeCounter += cumulative_time_delta; + accumulator.mSelfTimeCounter += self_time_delta; + accumulator.mTotalTimeCounter += cumulative_time_delta; cur_timer->mStartTime = cur_time; cur_data = &cur_timer->mLastTimerData; cur_data->mChildTime += cumulative_time_delta; + accumulator = cur_data->mTimerData->getPrimaryAccumulator(); cur_timer = cur_timer->mLastTimerData.mCurTimer; } @@ -333,13 +342,14 @@ void BlockTimer::accumulateTimings() ++it) { BlockTimer* timerp = (*it); - timerp->mTreeTimeCounter = timerp->mSelfTimeCounter; + TimerAccumulator& accumulator = timerp->getPrimaryAccumulator(); + timerp->mTreeTimeCounter = accumulator.mSelfTimeCounter; for (child_const_iter child_it = timerp->beginChildren(); child_it != timerp->endChildren(); ++child_it) { timerp->mTreeTimeCounter += (*child_it)->mTreeTimeCounter; } - S32 cur_frame = sCurFrameIndex; + S32 cur_frame = getCurFrameIndex(); if (cur_frame >= 0) { // update timer history @@ -347,8 +357,8 @@ void BlockTimer::accumulateTimings() timerp->mCountHistory[hidx] = timerp->mTreeTimeCounter; timerp->mCountAverage = ((U64)timerp->mCountAverage * cur_frame + timerp->mTreeTimeCounter) / (cur_frame+1); - timerp->mCallHistory[hidx] = timerp->mCalls; - timerp->mCallAverage = ((U64)timerp->mCallAverage * cur_frame + timerp->mCalls) / (cur_frame+1); + timerp->mCallHistory[hidx] = accumulator.mCalls; + timerp->mCallAverage = ((U64)timerp->mCallAverage * cur_frame + accumulator.mCalls) / (cur_frame+1); } } } @@ -377,15 +387,19 @@ void BlockTimer::resetFrame() LLSD sd; { - for (instance_iter it = beginInstances(), end_it = endInstances(); it != end_it; ++it) + for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), + end_it = LLInstanceTracker::endInstances(); + it != end_it; + ++it) { BlockTimer& timer = *it; - sd[timer.getName()]["Time"] = (LLSD::Real) (timer.mSelfTimeCounter*iclock_freq); - sd[timer.getName()]["Calls"] = (LLSD::Integer) timer.mCalls; + TimerAccumulator& accumulator = timer.getPrimaryAccumulator(); + sd[timer.getName()]["Time"] = (LLSD::Real) (accumulator.mSelfTimeCounter*iclock_freq); + sd[timer.getName()]["Calls"] = (LLSD::Integer) accumulator.mCalls; // computing total time here because getting the root timer's getCountHistory // doesn't work correctly on the first frame - total_time = total_time + timer.mSelfTimeCounter * iclock_freq; + total_time = total_time + accumulator.mSelfTimeCounter * iclock_freq; } } @@ -399,13 +413,17 @@ void BlockTimer::resetFrame() } // reset for next frame - for (instance_iter it = beginInstances(), end_it = endInstances(); it != end_it; ++it) + for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), + end_it = LLInstanceTracker::endInstances(); + it != end_it; + ++it) { BlockTimer& timer = *it; - timer.mSelfTimeCounter = 0; - timer.mCalls = 0; - timer.mLastCaller = NULL; - timer.mMoveUpTree = false; + TimerAccumulator& accumulator = timer.getPrimaryAccumulator(); + accumulator.mSelfTimeCounter = 0; + accumulator.mCalls = 0; + accumulator.mLastCaller = NULL; + accumulator.mMoveUpTree = false; } } @@ -419,7 +437,7 @@ void BlockTimer::reset() U32 cur_time = getCPUClockCount32(); // root defined by parent pointing to self - CurTimerData* cur_data = &sCurTimerData; + CurTimerData* cur_data = sCurTimerData.get(); Time* cur_timer = cur_data->mCurTimer; while(cur_timer && cur_timer->mLastTimerData.mCurTimer != cur_timer) { @@ -432,7 +450,10 @@ void BlockTimer::reset() // reset all history { - for (instance_iter it = beginInstances(), end_it = endInstances(); it != end_it; ++it) + for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), + end_it = LLInstanceTracker::endInstances(); + it != end_it; + ++it) { BlockTimer& timer = *it; if (&timer != &BlockTimer::getRootTimer()) @@ -453,13 +474,13 @@ void BlockTimer::reset() U32 BlockTimer::getHistoricalCount(S32 history_index) const { - S32 history_idx = (getLastFrameIndex() + history_index) % BlockTimer::HISTORY_NUM; + S32 history_idx = (getLastFrameIndex() + history_index) % HISTORY_NUM; return mCountHistory[history_idx]; } U32 BlockTimer::getHistoricalCalls(S32 history_index ) const { - S32 history_idx = (getLastFrameIndex() + history_index) % BlockTimer::HISTORY_NUM; + S32 history_idx = (getLastFrameIndex() + history_index) % HISTORY_NUM; return mCallHistory[history_idx]; } @@ -479,10 +500,10 @@ std::vector& BlockTimer::getChildren() } //static -void Time::nextFrame() +void BlockTimer::nextFrame() { - countsPerSecond(); // good place to calculate clock frequency - U64 frame_time = getCPUClockCount64(); + BlockTimer::countsPerSecond(); // good place to calculate clock frequency + U64 frame_time = BlockTimer::getCPUClockCount64(); if ((frame_time - sLastFrameTime) >> 8 > 0xffffffff) { llinfos << "Slow frame, fast timers inaccurate" << llendl; @@ -505,7 +526,7 @@ void Time::dumpCurTimes() // accumulate timings, etc. BlockTimer::processTimes(); - F64 clock_freq = (F64)countsPerSecond(); + F64 clock_freq = (F64)BlockTimer::countsPerSecond(); F64 iclock_freq = 1000.0 / clock_freq; // clock_ticks -> milliseconds // walk over timers in depth order and output timings @@ -533,13 +554,6 @@ void Time::dumpCurTimes() } } -//static -void Time::reset() -{ - BlockTimer::reset(); -} - - //static void Time::writeLog(std::ostream& os) { -- cgit v1.2.3 From c136b432140f892a56d4996d5ed77e903ff0b32d Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Thu, 15 Nov 2012 19:46:09 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system eliminated min and max macros from windows.h got rest of viewer to compile against llfasttimer changes --- indra/llcommon/llfasttimer.cpp | 5 +++++ 1 file changed, 5 insertions(+) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index d007f76e5f..4ecca12832 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -121,6 +121,11 @@ void BlockTimer::pushLog(LLSD log) sLogQueue.push(log); } +void BlockTimer::setLogLock(LLMutex* lock) +{ + sLogLock = lock; +} + //static #if (LL_DARWIN || LL_LINUX || LL_SOLARIS) && !(defined(__i386__) || defined(__amd64__)) -- cgit v1.2.3 From 6db6cb39f41e921e75970d1570a74cf35d353a35 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Fri, 16 Nov 2012 23:02:53 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system got new fast timer code to compile and run --- indra/llcommon/llfasttimer.cpp | 13 ++++++++++++- 1 file changed, 12 insertions(+), 1 deletion(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 4ecca12832..e1549b4bff 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -336,7 +336,10 @@ void BlockTimer::accumulateTimings() cur_data = &cur_timer->mLastTimerData; cur_data->mChildTime += cumulative_time_delta; - accumulator = cur_data->mTimerData->getPrimaryAccumulator(); + if (cur_data->mTimerData) + { + accumulator = cur_data->mTimerData->getPrimaryAccumulator(); + } cur_timer = cur_timer->mLastTimerData.mCurTimer; } @@ -572,6 +575,14 @@ void Time::writeLog(std::ostream& os) } +LLTrace::TimerAccumulator::TimerAccumulator() : mSelfTimeCounter(0), + mTotalTimeCounter(0), + mCalls(0), + mLastCaller(NULL), + mActiveCount(0), + mMoveUpTree(false) +{} + void LLTrace::TimerAccumulator::addSamples( const LLTrace::TimerAccumulator& other ) { mSelfTimeCounter += other.mSelfTimeCounter; -- cgit v1.2.3 From 1c894c05c10ef37be6507ee4bc4e9173506adfb6 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Tue, 27 Nov 2012 17:26:12 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system hunting down bad values and crashes --- indra/llcommon/llfasttimer.cpp | 24 ++++++++++++++---------- 1 file changed, 14 insertions(+), 10 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index e1549b4bff..16dd21332c 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -177,8 +177,8 @@ BlockTimer::BlockTimer(const char* name, bool open, BlockTimer* parent) mParent = this; } - mCountHistory = new U32[HISTORY_NUM]; - memset(mCountHistory, 0, sizeof(U32) * HISTORY_NUM); + mCountHistory = new U64[HISTORY_NUM]; + memset(mCountHistory, 0, sizeof(U64) * HISTORY_NUM); mCallHistory = new U32[HISTORY_NUM]; memset(mCallHistory, 0, sizeof(U32) * HISTORY_NUM); } @@ -266,9 +266,12 @@ void BlockTimer::buildHierarchy() // bootstrap tree construction by attaching to last timer to be on stack // when this timer was called - if (timer.getPrimaryAccumulator().mLastCaller && timer.mParent == &BlockTimer::getRootTimer()) + if (timer.mParent == &BlockTimer::getRootTimer()) { - timer.setParent(timer.getPrimaryAccumulator().mLastCaller); + if (timer.getPrimaryAccumulator().mLastCaller) + { + timer.setParent(timer.getPrimaryAccumulator().mLastCaller); + } // no need to push up tree on first use, flag can be set spuriously timer.getPrimaryAccumulator().mMoveUpTree = false; } @@ -317,7 +320,7 @@ void BlockTimer::buildHierarchy() //static void BlockTimer::accumulateTimings() { - U32 cur_time = getCPUClockCount32(); + U64 cur_time = getCPUClockCount64(); // walk up stack of active timers and accumulate current time while leaving timing structures active Time* cur_timer = sCurTimerData->mCurTimer; @@ -326,8 +329,8 @@ void BlockTimer::accumulateTimings() TimerAccumulator& accumulator = sCurTimerData->mTimerData->getPrimaryAccumulator(); while(cur_timer && cur_timer->mLastTimerData.mCurTimer != cur_timer) { - U32 cumulative_time_delta = cur_time - cur_timer->mStartTime; - U32 self_time_delta = cumulative_time_delta - cur_data->mChildTime; + U64 cumulative_time_delta = cur_time - cur_timer->mStartTime; + U64 self_time_delta = cumulative_time_delta - cur_data->mChildTime; cur_data->mChildTime = 0; accumulator.mSelfTimeCounter += self_time_delta; accumulator.mTotalTimeCounter += cumulative_time_delta; @@ -429,6 +432,7 @@ void BlockTimer::resetFrame() BlockTimer& timer = *it; TimerAccumulator& accumulator = timer.getPrimaryAccumulator(); accumulator.mSelfTimeCounter = 0; + accumulator.mTotalTimeCounter = 0; accumulator.mCalls = 0; accumulator.mLastCaller = NULL; accumulator.mMoveUpTree = false; @@ -442,7 +446,7 @@ void BlockTimer::reset() // walk up stack of active timers and reset start times to current time // effectively zeroing out any accumulated time - U32 cur_time = getCPUClockCount32(); + U64 cur_time = getCPUClockCount64(); // root defined by parent pointing to self CurTimerData* cur_data = sCurTimerData.get(); @@ -471,7 +475,7 @@ void BlockTimer::reset() timer.mCountAverage = 0; timer.mCallAverage = 0; - memset(timer.mCountHistory, 0, sizeof(U32) * HISTORY_NUM); + memset(timer.mCountHistory, 0, sizeof(U64) * HISTORY_NUM); memset(timer.mCallHistory, 0, sizeof(U32) * HISTORY_NUM); } } @@ -480,7 +484,7 @@ void BlockTimer::reset() sCurFrameIndex = 0; } -U32 BlockTimer::getHistoricalCount(S32 history_index) const +U64 BlockTimer::getHistoricalCount(S32 history_index) const { S32 history_idx = (getLastFrameIndex() + history_index) % HISTORY_NUM; return mCountHistory[history_idx]; -- cgit v1.2.3 From 93aca485ba08a82a6bd3a2fc31deca18af0d1478 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Tue, 27 Nov 2012 20:17:37 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system fixed precision of fast timer counts --- indra/llcommon/llfasttimer.cpp | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index e1549b4bff..9701a41dc5 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -317,7 +317,7 @@ void BlockTimer::buildHierarchy() //static void BlockTimer::accumulateTimings() { - U32 cur_time = getCPUClockCount32(); + U64 cur_time = getCPUClockCount64(); // walk up stack of active timers and accumulate current time while leaving timing structures active Time* cur_timer = sCurTimerData->mCurTimer; @@ -389,7 +389,7 @@ void BlockTimer::resetFrame() } call_count++; - F64 iclock_freq = 1000.0 / countsPerSecond(); // good place to calculate clock frequency + F64 iclock_freq = 1000.0 / get_clock_count(); // good place to calculate clock frequency F64 total_time = 0; LLSD sd; @@ -442,7 +442,7 @@ void BlockTimer::reset() // walk up stack of active timers and reset start times to current time // effectively zeroing out any accumulated time - U32 cur_time = getCPUClockCount32(); + U64 cur_time = getCPUClockCount64(); // root defined by parent pointing to self CurTimerData* cur_data = sCurTimerData.get(); @@ -510,7 +510,7 @@ std::vector& BlockTimer::getChildren() //static void BlockTimer::nextFrame() { - BlockTimer::countsPerSecond(); // good place to calculate clock frequency + get_clock_count(); // good place to calculate clock frequency U64 frame_time = BlockTimer::getCPUClockCount64(); if ((frame_time - sLastFrameTime) >> 8 > 0xffffffff) { @@ -534,7 +534,7 @@ void Time::dumpCurTimes() // accumulate timings, etc. BlockTimer::processTimes(); - F64 clock_freq = (F64)BlockTimer::countsPerSecond(); + F64 clock_freq = (F64)get_clock_count(); F64 iclock_freq = 1000.0 / clock_freq; // clock_ticks -> milliseconds // walk over timers in depth order and output timings -- cgit v1.2.3 From 02d503bf8f8890c6d4b57dd09a1fde2973715b75 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Thu, 29 Nov 2012 00:43:25 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system moved runtime timer tree topology information to separate array instead of recording stack --- indra/llcommon/llfasttimer.cpp | 85 ++++++++++++++++++++++-------------------- 1 file changed, 45 insertions(+), 40 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index e88a5a9ed1..1b3498cce3 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -58,24 +58,27 @@ namespace LLTrace ////////////////////////////////////////////////////////////////////////////// // statics -S32 BlockTimer::sCurFrameIndex = -1; -S32 BlockTimer::sLastFrameIndex = -1; -U64 BlockTimer::sLastFrameTime = BlockTimer::getCPUClockCount64(); -bool BlockTimer::sPauseHistory = 0; -bool BlockTimer::sResetHistory = 0; -LLThreadLocalPointer BlockTimer::sCurTimerData; -bool BlockTimer::sLog = false; -std::string BlockTimer::sLogName = ""; -bool BlockTimer::sMetricLog = false; -static LLMutex* sLogLock = NULL; -static std::queue sLogQueue; +S32 BlockTimer::sCurFrameIndex = -1; +S32 BlockTimer::sLastFrameIndex = -1; +U64 BlockTimer::sLastFrameTime = BlockTimer::getCPUClockCount64(); +bool BlockTimer::sPauseHistory = 0; +bool BlockTimer::sResetHistory = 0; +bool BlockTimer::sLog = false; +std::string BlockTimer::sLogName = ""; +bool BlockTimer::sMetricLog = false; #if LL_LINUX || LL_SOLARIS -U64 BlockTimer::sClockResolution = 1000000000; // Nanosecond resolution +U64 BlockTimer::sClockResolution = 1000000000; // Nanosecond resolution #else -U64 BlockTimer::sClockResolution = 1000000; // Microsecond resolution +U64 BlockTimer::sClockResolution = 1000000; // Microsecond resolution #endif +LLThreadLocalPointer BlockTimer::sCurTimerData; + +static LLMutex* sLogLock = NULL; +static std::queue sLogQueue; + + // FIXME: move these declarations to the relevant modules // helper functions @@ -108,6 +111,7 @@ static timer_tree_dfs_iterator_t end_timer_tree() return timer_tree_dfs_iterator_t(); } + BlockTimer& BlockTimer::getRootTimer() { static BlockTimer root_timer("root", true, NULL); @@ -142,7 +146,7 @@ U64 BlockTimer::countsPerSecond() // counts per second for the *32-bit* timer // 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. + // If we're not using RDTSC, each fast timer tick is just a performance counter tick. // Not redefining the clock frequency itself (in llprocessor.cpp/calculate_cpu_frequency()) // since that would change displayed MHz stats for CPUs static bool firstcall = true; @@ -268,17 +272,19 @@ void BlockTimer::buildHierarchy() // when this timer was called if (timer.mParent == &BlockTimer::getRootTimer()) { - if (timer.getPrimaryAccumulator().mLastCaller) - { - timer.setParent(timer.getPrimaryAccumulator().mLastCaller); + TimerTreeNode& tree_node = sCurTimerData->mTimerTreeData[timer.getIndex()]; + + if (tree_node.mLastCaller) + { + timer.setParent(tree_node.mLastCaller); } // no need to push up tree on first use, flag can be set spuriously - timer.getPrimaryAccumulator().mMoveUpTree = false; + tree_node.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(BlockTimer::getRootTimer()); @@ -288,15 +294,16 @@ void BlockTimer::buildHierarchy() BlockTimer* timerp = *it; // skip root timer if (timerp == &BlockTimer::getRootTimer()) continue; + TimerTreeNode& tree_node = sCurTimerData->mTimerTreeData[timerp->getIndex()]; - if (timerp->getPrimaryAccumulator().mMoveUpTree) + if (tree_node.mMoveUpTree) { // 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->getPrimaryAccumulator().mMoveUpTree = false; + tree_node.mMoveUpTree = false; // don't bubble up any ancestors until descendants are done bubbling up it.skipAncestors(); @@ -322,11 +329,11 @@ void BlockTimer::accumulateTimings() { U64 cur_time = getCPUClockCount64(); - // walk up stack of active timers and accumulate current time while leaving timing structures active - Time* cur_timer = sCurTimerData->mCurTimer; // root defined by parent pointing to self CurTimerData* cur_data = sCurTimerData.get(); - TimerAccumulator& accumulator = sCurTimerData->mTimerData->getPrimaryAccumulator(); + // walk up stack of active timers and accumulate current time while leaving timing structures active + Time* cur_timer = cur_data->mCurTimer; + TimerAccumulator& accumulator = cur_data->mTimerData->getPrimaryAccumulator(); while(cur_timer && cur_timer->mLastTimerData.mCurTimer != cur_timer) { U64 cumulative_time_delta = cur_time - cur_timer->mStartTime; @@ -431,11 +438,13 @@ void BlockTimer::resetFrame() { BlockTimer& timer = *it; TimerAccumulator& accumulator = timer.getPrimaryAccumulator(); + TimerTreeNode& tree_node = sCurTimerData->mTimerTreeData[timer.getIndex()]; + accumulator.mSelfTimeCounter = 0; accumulator.mTotalTimeCounter = 0; accumulator.mCalls = 0; - accumulator.mLastCaller = NULL; - accumulator.mMoveUpTree = false; + tree_node.mLastCaller = NULL; + tree_node.mMoveUpTree = false; } } @@ -579,32 +588,28 @@ void Time::writeLog(std::ostream& os) } -LLTrace::TimerAccumulator::TimerAccumulator() : mSelfTimeCounter(0), +TimerAccumulator::TimerAccumulator() : mSelfTimeCounter(0), mTotalTimeCounter(0), - mCalls(0), - mLastCaller(NULL), - mActiveCount(0), - mMoveUpTree(false) + mCalls(0) {} -void LLTrace::TimerAccumulator::addSamples( const LLTrace::TimerAccumulator& other ) +void TimerAccumulator::addSamples( const TimerAccumulator& other ) { mSelfTimeCounter += other.mSelfTimeCounter; mTotalTimeCounter += other.mTotalTimeCounter; mCalls += other.mCalls; - if (!mLastCaller) - { - mLastCaller = other.mLastCaller; - } - - //mActiveCount stays the same; - mMoveUpTree |= other.mMoveUpTree; } -void LLTrace::TimerAccumulator::reset( const LLTrace::TimerAccumulator* other ) +void TimerAccumulator::reset( const TimerAccumulator* other ) { mTotalTimeCounter = 0; mSelfTimeCounter = 0; mCalls = 0; } + +TimerTreeNode::TimerTreeNode() +: mLastCaller(NULL), + mActiveCount(0), + mMoveUpTree(false) +{} } -- cgit v1.2.3 From ca2207bd35c33b13b122f875a5a7d218f94ca3fc Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Sat, 1 Dec 2012 00:17:04 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system fixed scale of reported times moved reset calls to happen at same time so we don't show partial results --- indra/llcommon/llfasttimer.cpp | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 1b3498cce3..19676cc0c6 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -144,7 +144,6 @@ U64 BlockTimer::countsPerSecond() // counts per second for the *32-bit* timer //getCPUFrequency returns MHz and sCPUClockFrequency wants to be in Hz static LLUnit 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 fast timer tick is just a performance counter tick. // Not redefining the clock frequency itself (in llprocessor.cpp/calculate_cpu_frequency()) @@ -157,7 +156,7 @@ U64 BlockTimer::countsPerSecond() // counts per second for the *32-bit* timer firstcall = false; } #endif - return sCPUClockFrequency >> 8; + return sCPUClockFrequency; } #endif @@ -390,8 +389,7 @@ void BlockTimer::resetFrame() 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() << LL_ENDL; + 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; -- cgit v1.2.3 From 13e4edf1cd664864afa585bc83bbe99d4f743326 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Sun, 2 Dec 2012 23:00:36 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system started moving fast timer historical stats over to LLTrace periodic recording --- indra/llcommon/llfasttimer.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 19676cc0c6..e33cb76eff 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -133,12 +133,12 @@ void BlockTimer::setLogLock(LLMutex* lock) //static #if (LL_DARWIN || LL_LINUX || LL_SOLARIS) && !(defined(__i386__) || defined(__amd64__)) -U64 BlockTimer::countsPerSecond() // counts per second for the *32-bit* timer +U64 BlockTimer::countsPerSecond() // counts per second for the *64-bit* timer { - return sClockResolution >> 8; + return sClockResolution; } #else // windows or x86-mac or x86-linux or x86-solaris -U64 BlockTimer::countsPerSecond() // counts per second for the *32-bit* timer +U64 BlockTimer::countsPerSecond() // counts per second for the *64-bit* timer { #if LL_FASTTIMER_USE_RDTSC || !LL_WINDOWS //getCPUFrequency returns MHz and sCPUClockFrequency wants to be in Hz -- cgit v1.2.3 From 407e5013f3845208e0a60e26e8f0a7fad997df5d Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Mon, 3 Dec 2012 19:54:53 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system converted fast timer view over to new lltrace mechanisms --- indra/llcommon/llfasttimer.cpp | 538 +++++++++++++++++------------------------ 1 file changed, 228 insertions(+), 310 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index e33cb76eff..cf7655acf7 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -34,6 +34,7 @@ #include "llsdserialize.h" #include "llunit.h" #include "llsd.h" +#include "lltracerecording.h" #include #include @@ -58,22 +59,22 @@ namespace LLTrace ////////////////////////////////////////////////////////////////////////////// // statics -S32 BlockTimer::sCurFrameIndex = -1; -S32 BlockTimer::sLastFrameIndex = -1; -U64 BlockTimer::sLastFrameTime = BlockTimer::getCPUClockCount64(); -bool BlockTimer::sPauseHistory = 0; -bool BlockTimer::sResetHistory = 0; -bool BlockTimer::sLog = false; -std::string BlockTimer::sLogName = ""; -bool BlockTimer::sMetricLog = false; +S32 TimeBlock::sCurFrameIndex = -1; +S32 TimeBlock::sLastFrameIndex = -1; +U64 TimeBlock::sLastFrameTime = TimeBlock::getCPUClockCount64(); +bool TimeBlock::sPauseHistory = 0; +bool TimeBlock::sResetHistory = 0; +bool TimeBlock::sLog = false; +std::string TimeBlock::sLogName = ""; +bool TimeBlock::sMetricLog = false; #if LL_LINUX || LL_SOLARIS -U64 BlockTimer::sClockResolution = 1000000000; // Nanosecond resolution +U64 TimeBlock::sClockResolution = 1000000000; // Nanosecond resolution #else -U64 BlockTimer::sClockResolution = 1000000; // Microsecond resolution +U64 TimeBlock::sClockResolution = 1000000; // Microsecond resolution #endif -LLThreadLocalPointer BlockTimer::sCurTimerData; +LLThreadLocalPointer TimeBlock::sCurTimerData; static LLMutex* sLogLock = NULL; static std::queue sLogQueue; @@ -82,13 +83,13 @@ static std::queue sLogQueue; // FIXME: move these declarations to the relevant modules // helper functions -typedef LLTreeDFSPostIter timer_tree_bottom_up_iterator_t; +typedef LLTreeDFSPostIter timer_tree_bottom_up_iterator_t; -static timer_tree_bottom_up_iterator_t begin_timer_tree_bottom_up(BlockTimer& 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(&BlockTimer::beginChildren), _1), - boost::bind(boost::mem_fn(&BlockTimer::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() @@ -96,14 +97,14 @@ static timer_tree_bottom_up_iterator_t end_timer_tree_bottom_up() return timer_tree_bottom_up_iterator_t(); } -typedef LLTreeDFSIter timer_tree_dfs_iterator_t; +typedef LLTreeDFSIter timer_tree_dfs_iterator_t; -static timer_tree_dfs_iterator_t begin_timer_tree(BlockTimer& id) +static timer_tree_dfs_iterator_t begin_timer_tree(TimeBlock& id) { return timer_tree_dfs_iterator_t(&id, - boost::bind(boost::mem_fn(&BlockTimer::beginChildren), _1), - boost::bind(boost::mem_fn(&BlockTimer::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() @@ -112,20 +113,29 @@ static timer_tree_dfs_iterator_t end_timer_tree() } -BlockTimer& BlockTimer::getRootTimer() +// sort child timers by name +struct SortTimerByName { - static BlockTimer root_timer("root", true, NULL); + bool operator()(const TimeBlock* i1, const TimeBlock* i2) + { + return i1->getName() < i2->getName(); + } +}; + +TimeBlock& TimeBlock::getRootTimer() +{ + static TimeBlock root_timer("root", true, NULL); return root_timer; } -void BlockTimer::pushLog(LLSD log) +void TimeBlock::pushLog(LLSD log) { LLMutexLock lock(sLogLock); sLogQueue.push(log); } -void BlockTimer::setLogLock(LLMutex* lock) +void TimeBlock::setLogLock(LLMutex* lock) { sLogLock = lock; } @@ -133,12 +143,12 @@ void BlockTimer::setLogLock(LLMutex* lock) //static #if (LL_DARWIN || LL_LINUX || LL_SOLARIS) && !(defined(__i386__) || defined(__amd64__)) -U64 BlockTimer::countsPerSecond() // counts per second for the *64-bit* timer +U64 TimeBlock::countsPerSecond() // counts per second for the *64-bit* timer { return sClockResolution; } #else // windows or x86-mac or x86-linux or x86-solaris -U64 BlockTimer::countsPerSecond() // counts per second for the *64-bit* timer +U64 TimeBlock::countsPerSecond() // counts per second for the *64-bit* timer { #if LL_FASTTIMER_USE_RDTSC || !LL_WINDOWS //getCPUFrequency returns MHz and sCPUClockFrequency wants to be in Hz @@ -160,13 +170,10 @@ U64 BlockTimer::countsPerSecond() // counts per second for the *64-bit* timer } #endif -BlockTimer::BlockTimer(const char* name, bool open, BlockTimer* parent) +TimeBlock::TimeBlock(const char* name, bool open, TimeBlock* parent) : TraceType(name), mCollapsed(true), mParent(NULL), - mTreeTimeCounter(0), - mCountAverage(0), - mCallAverage(0), mNeedsSorting(false) { setCollapsed(!open); @@ -179,37 +186,26 @@ BlockTimer::BlockTimer(const char* name, bool open, BlockTimer* parent) { mParent = this; } - - mCountHistory = new U64[HISTORY_NUM]; - memset(mCountHistory, 0, sizeof(U64) * HISTORY_NUM); - mCallHistory = new U32[HISTORY_NUM]; - memset(mCallHistory, 0, sizeof(U32) * HISTORY_NUM); } -BlockTimer::~BlockTimer() -{ - delete[] mCountHistory; - delete[] mCallHistory; -} - -void BlockTimer::setParent(BlockTimer* parent) +void TimeBlock::setParent(TimeBlock* 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 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; + //// subtract average timing from previous parent + //mParent->mCountAverage -= mCountAverage; - std::vector& children = mParent->getChildren(); - std::vector::iterator found_it = std::find(children.begin(), children.end(), this); + std::vector& children = mParent->getChildren(); + std::vector::iterator found_it = std::find(children.begin(), children.end(), this); if (found_it != children.end()) { children.erase(found_it); @@ -224,10 +220,10 @@ void BlockTimer::setParent(BlockTimer* parent) } } -S32 BlockTimer::getDepth() +S32 TimeBlock::getDepth() { S32 depth = 0; - BlockTimer* timerp = mParent; + TimeBlock* timerp = mParent; while(timerp) { depth++; @@ -238,291 +234,152 @@ S32 BlockTimer::getDepth() } // static -void BlockTimer::processTimes() +void TimeBlock::processTimes() { - if (getCurFrameIndex() < 0) return; - - buildHierarchy(); - accumulateTimings(); -} - -// sort child timers by name -struct SortTimerByName -{ - bool operator()(const BlockTimer* i1, const BlockTimer* i2) - { - return i1->getName() < i2->getName(); - } -}; - -//static -void BlockTimer::buildHierarchy() -{ - if (getCurFrameIndex() < 0 ) return; - - // set up initial tree + //void TimeBlock::buildHierarchy() { - for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), end_it = LLInstanceTracker::endInstances(); it != end_it; ++it) + // set up initial tree { - BlockTimer& timer = *it; - if (&timer == &BlockTimer::getRootTimer()) continue; - - // bootstrap tree construction by attaching to last timer to be on stack - // when this timer was called - if (timer.mParent == &BlockTimer::getRootTimer()) + for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), end_it = LLInstanceTracker::endInstances(); it != end_it; ++it) { - TimerTreeNode& tree_node = sCurTimerData->mTimerTreeData[timer.getIndex()]; + TimeBlock& timer = *it; + if (&timer == &TimeBlock::getRootTimer()) continue; - if (tree_node.mLastCaller) + // bootstrap tree construction by attaching to last timer to be on stack + // when this timer was called + if (timer.mParent == &TimeBlock::getRootTimer()) { - timer.setParent(tree_node.mLastCaller); + TimeBlockTreeNode& tree_node = sCurTimerData->mTimerTreeData[timer.getIndex()]; + + if (tree_node.mLastCaller) + { + timer.setParent(tree_node.mLastCaller); + } + // no need to push up tree on first use, flag can be set spuriously + tree_node.mMoveUpTree = false; } - // no need to push up tree on first use, flag can be set spuriously - tree_node.mMoveUpTree = false; } } - } - - // 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(BlockTimer::getRootTimer()); - it != end_timer_tree_bottom_up(); - ++it) - { - BlockTimer* timerp = *it; - // skip root timer - if (timerp == &BlockTimer::getRootTimer()) continue; - TimerTreeNode& tree_node = sCurTimerData->mTimerTreeData[timerp->getIndex()]; - if (tree_node.mMoveUpTree) + // 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(TimeBlock::getRootTimer()); + it != end_timer_tree_bottom_up(); + ++it) { - // 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()); - tree_node.mMoveUpTree = false; + TimeBlock* timerp = *it; + // skip root timer + if (timerp == &TimeBlock::getRootTimer()) continue; + TimeBlockTreeNode& tree_node = sCurTimerData->mTimerTreeData[timerp->getIndex()]; - // don't bubble up any ancestors until descendants are done bubbling up - it.skipAncestors(); - } - } + if (tree_node.mMoveUpTree) + { + // 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()); + tree_node.mMoveUpTree = false; - // sort timers by time last called, so call graph makes sense - for(timer_tree_dfs_iterator_t it = begin_timer_tree(BlockTimer::getRootTimer()); - it != end_timer_tree(); - ++it) - { - BlockTimer* timerp = (*it); - if (timerp->mNeedsSorting) - { - std::sort(timerp->getChildren().begin(), timerp->getChildren().end(), SortTimerByName()); + // don't bubble up any ancestors until descendants are done bubbling up + it.skipAncestors(); + } } - timerp->mNeedsSorting = false; - } -} - -//static -void BlockTimer::accumulateTimings() -{ - U64 cur_time = getCPUClockCount64(); - - // root defined by parent pointing to self - CurTimerData* cur_data = sCurTimerData.get(); - // walk up stack of active timers and accumulate current time while leaving timing structures active - Time* cur_timer = cur_data->mCurTimer; - TimerAccumulator& accumulator = cur_data->mTimerData->getPrimaryAccumulator(); - while(cur_timer && cur_timer->mLastTimerData.mCurTimer != cur_timer) - { - U64 cumulative_time_delta = cur_time - cur_timer->mStartTime; - U64 self_time_delta = cumulative_time_delta - cur_data->mChildTime; - cur_data->mChildTime = 0; - accumulator.mSelfTimeCounter += self_time_delta; - accumulator.mTotalTimeCounter += cumulative_time_delta; - - cur_timer->mStartTime = cur_time; - cur_data = &cur_timer->mLastTimerData; - cur_data->mChildTime += cumulative_time_delta; - if (cur_data->mTimerData) + // sort timers by time last called, so call graph makes sense + for(timer_tree_dfs_iterator_t it = begin_timer_tree(TimeBlock::getRootTimer()); + it != end_timer_tree(); + ++it) { - accumulator = cur_data->mTimerData->getPrimaryAccumulator(); + TimeBlock* timerp = (*it); + if (timerp->mNeedsSorting) + { + std::sort(timerp->getChildren().begin(), timerp->getChildren().end(), SortTimerByName()); + } + timerp->mNeedsSorting = false; } - - cur_timer = cur_timer->mLastTimerData.mCurTimer; } - - // traverse tree in DFS post order, or bottom up - for(timer_tree_bottom_up_iterator_t it = begin_timer_tree_bottom_up(BlockTimer::getRootTimer()); - it != end_timer_tree_bottom_up(); - ++it) + + //void TimeBlock::accumulateTimings() { - BlockTimer* timerp = (*it); - TimerAccumulator& accumulator = timerp->getPrimaryAccumulator(); - timerp->mTreeTimeCounter = accumulator.mSelfTimeCounter; - for (child_const_iter child_it = timerp->beginChildren(); child_it != timerp->endChildren(); ++child_it) - { - timerp->mTreeTimeCounter += (*child_it)->mTreeTimeCounter; - } - - S32 cur_frame = getCurFrameIndex(); - if (cur_frame >= 0) + U64 cur_time = getCPUClockCount64(); + + // root defined by parent pointing to self + CurTimerData* cur_data = sCurTimerData.get(); + // walk up stack of active timers and accumulate current time while leaving timing structures active + BlockTimer* cur_timer = cur_data->mCurTimer; + TimeBlockAccumulator& accumulator = cur_data->mTimerData->getPrimaryAccumulator(); + while(cur_timer && cur_timer->mLastTimerData.mCurTimer != cur_timer) { - // update timer history - int hidx = cur_frame % HISTORY_NUM; + U64 cumulative_time_delta = cur_time - cur_timer->mStartTime; + U64 self_time_delta = cumulative_time_delta - cur_data->mChildTime; + cur_data->mChildTime = 0; + accumulator.mSelfTimeCounter += self_time_delta; + accumulator.mTotalTimeCounter += cumulative_time_delta; - timerp->mCountHistory[hidx] = timerp->mTreeTimeCounter; - timerp->mCountAverage = ((U64)timerp->mCountAverage * cur_frame + timerp->mTreeTimeCounter) / (cur_frame+1); - timerp->mCallHistory[hidx] = accumulator.mCalls; - timerp->mCallAverage = ((U64)timerp->mCallAverage * cur_frame + accumulator.mCalls) / (cur_frame+1); - } - } -} + cur_timer->mStartTime = cur_time; -// static -void BlockTimer::resetFrame() -{ - if (sLog) - { //output current frame counts to performance log - - static S32 call_count = 0; - if (call_count % 100 == 0) - { - 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()) / (LLUnit(LLProcessorInfo().getCPUFrequency())) << LL_ENDL; - } - call_count++; - - F64 iclock_freq = 1000.0 / get_clock_count(); // good place to calculate clock frequency - - F64 total_time = 0; - LLSD sd; - - { - for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), - end_it = LLInstanceTracker::endInstances(); - it != end_it; - ++it) + cur_data = &cur_timer->mLastTimerData; + cur_data->mChildTime += cumulative_time_delta; + if (cur_data->mTimerData) { - BlockTimer& timer = *it; - TimerAccumulator& accumulator = timer.getPrimaryAccumulator(); - sd[timer.getName()]["Time"] = (LLSD::Real) (accumulator.mSelfTimeCounter*iclock_freq); - sd[timer.getName()]["Calls"] = (LLSD::Integer) accumulator.mCalls; - - // computing total time here because getting the root timer's getCountHistory - // doesn't work correctly on the first frame - total_time = total_time + accumulator.mSelfTimeCounter * iclock_freq; + accumulator = cur_data->mTimerData->getPrimaryAccumulator(); } - } - sd["Total"]["Time"] = (LLSD::Real) total_time; - sd["Total"]["Calls"] = (LLSD::Integer) 1; - - { - LLMutexLock lock(sLogLock); - sLogQueue.push(sd); + cur_timer = cur_timer->mLastTimerData.mCurTimer; } - } - - // reset for next frame - for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), - end_it = LLInstanceTracker::endInstances(); - it != end_it; - ++it) - { - BlockTimer& timer = *it; - TimerAccumulator& accumulator = timer.getPrimaryAccumulator(); - TimerTreeNode& tree_node = sCurTimerData->mTimerTreeData[timer.getIndex()]; - - accumulator.mSelfTimeCounter = 0; - accumulator.mTotalTimeCounter = 0; - accumulator.mCalls = 0; - tree_node.mLastCaller = NULL; - tree_node.mMoveUpTree = false; - } -} - -//static -void BlockTimer::reset() -{ - resetFrame(); // reset frame data - - // walk up stack of active timers and reset start times to current time - // effectively zeroing out any accumulated time - U64 cur_time = getCPUClockCount64(); - - // root defined by parent pointing to self - CurTimerData* cur_data = sCurTimerData.get(); - Time* 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 (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), - end_it = LLInstanceTracker::endInstances(); - it != end_it; - ++it) - { - BlockTimer& timer = *it; - if (&timer != &BlockTimer::getRootTimer()) - { - timer.setParent(&BlockTimer::getRootTimer()); - } - - timer.mCountAverage = 0; - timer.mCallAverage = 0; - memset(timer.mCountHistory, 0, sizeof(U64) * HISTORY_NUM); - memset(timer.mCallHistory, 0, sizeof(U32) * HISTORY_NUM); - } + // traverse tree in DFS post order, or bottom up + //for(timer_tree_bottom_up_iterator_t it = begin_timer_tree_bottom_up(TimeBlock::getRootTimer()); + // it != end_timer_tree_bottom_up(); + // ++it) + //{ + // TimeBlock* timerp = (*it); + // TimeBlockAccumulator& accumulator = timerp->getPrimaryAccumulator(); + // timerp->mTreeTimeCounter = accumulator.mSelfTimeCounter; + // for (child_const_iter child_it = timerp->beginChildren(); child_it != timerp->endChildren(); ++child_it) + // { + // timerp->mTreeTimeCounter += (*child_it)->mTreeTimeCounter; + // } + + //S32 cur_frame = getCurFrameIndex(); + //if (cur_frame >= 0) + //{ + // // update timer history + + // int hidx = getCurFrameIndex() % HISTORY_NUM; + + // timerp->mCountHistory[hidx] = timerp->mTreeTimeCounter; + // timerp->mCountAverage = ((U64)timerp->mCountAverage * cur_frame + timerp->mTreeTimeCounter) / (cur_frame+1); + // timerp->mCallHistory[hidx] = accumulator.mCalls; + // timerp->mCallAverage = ((U64)timerp->mCallAverage * cur_frame + accumulator.mCalls) / (cur_frame+1); + //} + //} } - - sLastFrameIndex = 0; - sCurFrameIndex = 0; } -U64 BlockTimer::getHistoricalCount(S32 history_index) const -{ - S32 history_idx = (getLastFrameIndex() + history_index) % HISTORY_NUM; - return mCountHistory[history_idx]; -} - -U32 BlockTimer::getHistoricalCalls(S32 history_index ) const -{ - S32 history_idx = (getLastFrameIndex() + history_index) % HISTORY_NUM; - return mCallHistory[history_idx]; -} -std::vector::const_iterator BlockTimer::beginChildren() +std::vector::const_iterator TimeBlock::beginChildren() { return mChildren.begin(); } -std::vector::const_iterator BlockTimer::endChildren() +std::vector::const_iterator TimeBlock::endChildren() { return mChildren.end(); } -std::vector& BlockTimer::getChildren() +std::vector& TimeBlock::getChildren() { return mChildren; } //static -void BlockTimer::nextFrame() +void TimeBlock::nextFrame() { get_clock_count(); // good place to calculate clock frequency - U64 frame_time = BlockTimer::getCPUClockCount64(); + U64 frame_time = TimeBlock::getCPUClockCount64(); if ((frame_time - sLastFrameTime) >> 8 > 0xffffffff) { llinfos << "Slow frame, fast timers inaccurate" << llendl; @@ -530,31 +387,88 @@ void BlockTimer::nextFrame() if (!sPauseHistory) { - BlockTimer::processTimes(); + TimeBlock::processTimes(); sLastFrameIndex = sCurFrameIndex++; } // get ready for next frame - BlockTimer::resetFrame(); + //void TimeBlock::resetFrame() + { + if (sLog) + { //output current frame counts to performance log + + static S32 call_count = 0; + if (call_count % 100 == 0) + { + 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()) / (LLUnit(LLProcessorInfo().getCPUFrequency())) << LL_ENDL; + } + call_count++; + + LLUnit total_time = 0; + LLSD sd; + + { + for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), + end_it = LLInstanceTracker::endInstances(); + it != end_it; + ++it) + { + 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 += frame_recording.getLastRecordingPeriod().getSum(timer); + } + } + + sd["Total"]["Time"] = (LLSD::Real) total_time.value(); + sd["Total"]["Calls"] = (LLSD::Integer) 1; + + { + LLMutexLock lock(sLogLock); + sLogQueue.push(sd); + } + } + + // reset for next frame + for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), + end_it = LLInstanceTracker::endInstances(); + it != end_it; + ++it) + { + TimeBlock& timer = *it; + TimeBlockTreeNode& tree_node = sCurTimerData->mTimerTreeData[timer.getIndex()]; + + tree_node.mLastCaller = NULL; + tree_node.mMoveUpTree = false; + } + } sLastFrameTime = frame_time; } //static -void Time::dumpCurTimes() +void TimeBlock::dumpCurTimes() { // accumulate timings, etc. - BlockTimer::processTimes(); + processTimes(); - F64 clock_freq = (F64)get_clock_count(); - F64 iclock_freq = 1000.0 / clock_freq; // clock_ticks -> milliseconds - // walk over timers in depth order and output timings - for(timer_tree_dfs_iterator_t it = begin_timer_tree(BlockTimer::getRootTimer()); + for(timer_tree_dfs_iterator_t it = begin_timer_tree(TimeBlock::getRootTimer()); it != end_timer_tree(); ++it) { - BlockTimer* timerp = (*it); - F64 total_time_ms = ((F64)timerp->getHistoricalCount(0) * iclock_freq); + LLTrace::PeriodicRecording& frame_recording = LLTrace::get_frame_recording(); + TimeBlock* timerp = (*it); + LLUnit total_time_ms = frame_recording.getLastRecordingPeriod().getSum(*timerp); + U32 num_calls = frame_recording.getLastRecordingPeriod().getSum(timerp->callCount()); + // Don't bother with really brief times, keep output concise if (total_time_ms < 0.1) continue; @@ -564,17 +478,16 @@ void Time::dumpCurTimes() out_str << "\t"; } - out_str << timerp->getName() << " " - << std::setprecision(3) << total_time_ms << " ms, " - << timerp->getHistoricalCalls(0) << " calls"; + << std::setprecision(3) << total_time_ms.as() << " ms, " + << num_calls << " calls"; llinfos << out_str.str() << llendl; } } //static -void Time::writeLog(std::ostream& os) +void TimeBlock::writeLog(std::ostream& os) { while (!sLogQueue.empty()) { @@ -585,29 +498,34 @@ void Time::writeLog(std::ostream& os) } } +////////////////////////////////////////////////////////////////////////////////////////////////////////////////// +// TimeBlockAccumulator +////////////////////////////////////////////////////////////////////////////////////////////////////////////////// -TimerAccumulator::TimerAccumulator() : mSelfTimeCounter(0), +TimeBlockAccumulator::TimeBlockAccumulator() +: mSelfTimeCounter(0), mTotalTimeCounter(0), mCalls(0) {} -void TimerAccumulator::addSamples( const TimerAccumulator& other ) +void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other ) { mSelfTimeCounter += other.mSelfTimeCounter; mTotalTimeCounter += other.mTotalTimeCounter; mCalls += other.mCalls; } -void TimerAccumulator::reset( const TimerAccumulator* other ) +void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other ) { mTotalTimeCounter = 0; mSelfTimeCounter = 0; mCalls = 0; } -TimerTreeNode::TimerTreeNode() +TimeBlockTreeNode::TimeBlockTreeNode() : mLastCaller(NULL), mActiveCount(0), mMoveUpTree(false) {} -} + +} // namespace LLTrace -- cgit v1.2.3 From c99886d94389babc78e92bbfa5084fdd785915af Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Fri, 7 Dec 2012 15:20:12 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system improved unit tests for LLUnit renamed LLUnit to LLUnitImplicit with LLUnit being reserved for explicit units --- indra/llcommon/llfasttimer.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index cf7655acf7..37e0fbac0a 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -166,7 +166,7 @@ U64 TimeBlock::countsPerSecond() // counts per second for the *64-bit* timer firstcall = false; } #endif - return sCPUClockFrequency; + return sCPUClockFrequency.value(); } #endif @@ -408,7 +408,7 @@ void TimeBlock::nextFrame() } call_count++; - LLUnit total_time = 0; + LLUnit total_time(0); LLSD sd; { @@ -479,7 +479,7 @@ void TimeBlock::dumpCurTimes() } out_str << timerp->getName() << " " - << std::setprecision(3) << total_time_ms.as() << " ms, " + << std::setprecision(3) << total_time_ms.as().value() << " ms, " << num_calls << " calls"; llinfos << out_str.str() << llendl; -- cgit v1.2.3 From c219282f5de753a044cecb53bd806145f68add9a Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Tue, 18 Dec 2012 20:07:25 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system removed some potential data races got memory stats recording in trace system --- indra/llcommon/llfasttimer.cpp | 326 ++++++++++++++++++----------------------- 1 file changed, 139 insertions(+), 187 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 37e0fbac0a..f4fa8f1e61 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -59,11 +59,6 @@ namespace LLTrace ////////////////////////////////////////////////////////////////////////////// // statics -S32 TimeBlock::sCurFrameIndex = -1; -S32 TimeBlock::sLastFrameIndex = -1; -U64 TimeBlock::sLastFrameTime = TimeBlock::getCPUClockCount64(); -bool TimeBlock::sPauseHistory = 0; -bool TimeBlock::sResetHistory = 0; bool TimeBlock::sLog = false; std::string TimeBlock::sLogName = ""; bool TimeBlock::sMetricLog = false; @@ -220,143 +215,126 @@ void TimeBlock::setParent(TimeBlock* parent) } } -S32 TimeBlock::getDepth() -{ - S32 depth = 0; - TimeBlock* timerp = mParent; - while(timerp) - { - depth++; - if (timerp->getParent() == timerp) break; - timerp = timerp->mParent; - } - return depth; -} - // static void TimeBlock::processTimes() { - //void TimeBlock::buildHierarchy() + get_clock_count(); // good place to calculate clock frequency + U64 cur_time = getCPUClockCount64(); + CurTimerData* cur_data = sCurTimerData.get(); + + // set up initial tree + for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), end_it = LLInstanceTracker::endInstances(); + it != end_it; + ++it) { - // set up initial tree + TimeBlock& timer = *it; + if (&timer == &TimeBlock::getRootTimer()) continue; + + // bootstrap tree construction by attaching to last timer to be on stack + // when this timer was called + if (timer.mParent == &TimeBlock::getRootTimer()) { - for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), end_it = LLInstanceTracker::endInstances(); it != end_it; ++it) + TimeBlockAccumulator& accumulator = timer.getPrimaryAccumulator(); + + if (accumulator.mLastCaller) { - TimeBlock& timer = *it; - if (&timer == &TimeBlock::getRootTimer()) continue; - - // bootstrap tree construction by attaching to last timer to be on stack - // when this timer was called - if (timer.mParent == &TimeBlock::getRootTimer()) - { - TimeBlockTreeNode& tree_node = sCurTimerData->mTimerTreeData[timer.getIndex()]; - - if (tree_node.mLastCaller) - { - timer.setParent(tree_node.mLastCaller); - } - // no need to push up tree on first use, flag can be set spuriously - tree_node.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 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(TimeBlock::getRootTimer()); - it != end_timer_tree_bottom_up(); - ++it) + // 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(TimeBlock::getRootTimer()); + it != end_timer_tree_bottom_up(); + ++it) + { + TimeBlock* timerp = *it; + + // sort timers by time last called, so call graph makes sense + if (timerp->mNeedsSorting) { - TimeBlock* timerp = *it; - // skip root timer - if (timerp == &TimeBlock::getRootTimer()) continue; - TimeBlockTreeNode& tree_node = sCurTimerData->mTimerTreeData[timerp->getIndex()]; + std::sort(timerp->getChildren().begin(), timerp->getChildren().end(), SortTimerByName()); + } + + // skip root timer + if (timerp != &TimeBlock::getRootTimer()) + { + TimeBlockAccumulator& accumulator = timerp->getPrimaryAccumulator(); - if (tree_node.mMoveUpTree) + if (accumulator.mMoveUpTree) { // 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()); - tree_node.mMoveUpTree = false; + accumulator.mParent = timerp->mParent; + 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(TimeBlock::getRootTimer()); - it != end_timer_tree(); - ++it) - { - TimeBlock* timerp = (*it); - if (timerp->mNeedsSorting) - { - std::sort(timerp->getChildren().begin(), timerp->getChildren().end(), SortTimerByName()); - } - timerp->mNeedsSorting = false; - } } - - //void TimeBlock::accumulateTimings() - { - U64 cur_time = getCPUClockCount64(); - - // root defined by parent pointing to self - CurTimerData* cur_data = sCurTimerData.get(); - // walk up stack of active timers and accumulate current time while leaving timing structures active - BlockTimer* cur_timer = cur_data->mCurTimer; - TimeBlockAccumulator& accumulator = cur_data->mTimerData->getPrimaryAccumulator(); - while(cur_timer && cur_timer->mLastTimerData.mCurTimer != cur_timer) - { - U64 cumulative_time_delta = cur_time - cur_timer->mStartTime; - U64 self_time_delta = cumulative_time_delta - cur_data->mChildTime; - cur_data->mChildTime = 0; - accumulator.mSelfTimeCounter += self_time_delta; - accumulator.mTotalTimeCounter += cumulative_time_delta; - cur_timer->mStartTime = cur_time; + // walk up stack of active timers and accumulate current time while leaving timing structures active + BlockTimer* cur_timer = cur_data->mCurTimer; + TimeBlockAccumulator& accumulator = cur_data->mTimerData->getPrimaryAccumulator(); + // root defined by parent pointing to self + while(cur_timer && cur_timer->mLastTimerData.mCurTimer != cur_timer) + { + U64 cumulative_time_delta = cur_time - cur_timer->mStartTime; + U64 self_time_delta = cumulative_time_delta - cur_data->mChildTime; + cur_data->mChildTime = 0; + accumulator.mSelfTimeCounter += self_time_delta; + accumulator.mTotalTimeCounter += cumulative_time_delta; - cur_data = &cur_timer->mLastTimerData; - cur_data->mChildTime += cumulative_time_delta; - if (cur_data->mTimerData) - { - accumulator = cur_data->mTimerData->getPrimaryAccumulator(); - } + cur_timer->mStartTime = cur_time; - cur_timer = cur_timer->mLastTimerData.mCurTimer; + cur_data = &cur_timer->mLastTimerData; + cur_data->mChildTime += cumulative_time_delta; + if (cur_data->mTimerData) + { + accumulator = cur_data->mTimerData->getPrimaryAccumulator(); } - // traverse tree in DFS post order, or bottom up - //for(timer_tree_bottom_up_iterator_t it = begin_timer_tree_bottom_up(TimeBlock::getRootTimer()); - // it != end_timer_tree_bottom_up(); - // ++it) - //{ - // TimeBlock* timerp = (*it); - // TimeBlockAccumulator& accumulator = timerp->getPrimaryAccumulator(); - // timerp->mTreeTimeCounter = accumulator.mSelfTimeCounter; - // for (child_const_iter child_it = timerp->beginChildren(); child_it != timerp->endChildren(); ++child_it) - // { - // timerp->mTreeTimeCounter += (*child_it)->mTreeTimeCounter; - // } - - //S32 cur_frame = getCurFrameIndex(); - //if (cur_frame >= 0) - //{ - // // update timer history + cur_timer = cur_timer->mLastTimerData.mCurTimer; + } - // int hidx = getCurFrameIndex() % HISTORY_NUM; - // timerp->mCountHistory[hidx] = timerp->mTreeTimeCounter; - // timerp->mCountAverage = ((U64)timerp->mCountAverage * cur_frame + timerp->mTreeTimeCounter) / (cur_frame+1); - // timerp->mCallHistory[hidx] = accumulator.mCalls; - // timerp->mCallAverage = ((U64)timerp->mCallAverage * cur_frame + accumulator.mCalls) / (cur_frame+1); - //} - //} + // reset for next frame + for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), + end_it = LLInstanceTracker::endInstances(); + it != end_it; + ++it) + { + TimeBlock& timer = *it; + TimeBlockAccumulator& accumulator = timer.getPrimaryAccumulator(); + + accumulator.mLastCaller = NULL; + accumulator.mMoveUpTree = false; } + + // traverse tree in DFS post order, or bottom up + //for(timer_tree_bottom_up_iterator_t it = begin_timer_tree_bottom_up(TimeBlock::getRootTimer()); + // it != end_timer_tree_bottom_up(); + // ++it) + //{ + // TimeBlock* timerp = (*it); + // TimeBlockAccumulator& accumulator = timerp->getPrimaryAccumulator(); + // timerp->mTreeTimeCounter = accumulator.mSelfTimeCounter; + // for (child_const_iter child_it = timerp->beginChildren(); child_it != timerp->endChildren(); ++child_it) + // { + // timerp->mTreeTimeCounter += (*child_it)->mTreeTimeCounter; + // } + //} } @@ -376,106 +354,78 @@ std::vector& TimeBlock::getChildren() } //static -void TimeBlock::nextFrame() +void TimeBlock::logStats() { - get_clock_count(); // good place to calculate clock frequency - U64 frame_time = TimeBlock::getCPUClockCount64(); - if ((frame_time - sLastFrameTime) >> 8 > 0xffffffff) - { - llinfos << "Slow frame, fast timers inaccurate" << llendl; - } - - if (!sPauseHistory) - { - TimeBlock::processTimes(); - sLastFrameIndex = sCurFrameIndex++; - } - // get ready for next frame - //void TimeBlock::resetFrame() - { - if (sLog) - { //output current frame counts to performance log + if (sLog) + { //output current frame counts to performance log - static S32 call_count = 0; - if (call_count % 100 == 0) - { - 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()) / (LLUnit(LLProcessorInfo().getCPUFrequency())) << LL_ENDL; - } - call_count++; + static S32 call_count = 0; + if (call_count % 100 == 0) + { + 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()) / (LLUnit(LLProcessorInfo().getCPUFrequency())) << LL_ENDL; + } + call_count++; - LLUnit total_time(0); - LLSD sd; + LLUnit total_time(0); + LLSD sd; + { + for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), + end_it = LLInstanceTracker::endInstances(); + it != end_it; + ++it) { - for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), - end_it = LLInstanceTracker::endInstances(); - it != end_it; - ++it) - { - 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 += frame_recording.getLastRecordingPeriod().getSum(timer); - } - } - - sd["Total"]["Time"] = (LLSD::Real) total_time.value(); - sd["Total"]["Calls"] = (LLSD::Integer) 1; + 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())); - { - LLMutexLock lock(sLogLock); - sLogQueue.push(sd); + // computing total time here because getting the root timer's getCountHistory + // doesn't work correctly on the first frame + total_time += frame_recording.getLastRecordingPeriod().getSum(timer); } } - // reset for next frame - for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), - end_it = LLInstanceTracker::endInstances(); - it != end_it; - ++it) - { - TimeBlock& timer = *it; - TimeBlockTreeNode& tree_node = sCurTimerData->mTimerTreeData[timer.getIndex()]; + sd["Total"]["Time"] = (LLSD::Real) total_time.value(); + sd["Total"]["Calls"] = (LLSD::Integer) 1; - tree_node.mLastCaller = NULL; - tree_node.mMoveUpTree = false; + { + LLMutexLock lock(sLogLock); + sLogQueue.push(sd); } } - sLastFrameTime = frame_time; + } //static void TimeBlock::dumpCurTimes() { - // accumulate timings, etc. - processTimes(); - + 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(TimeBlock::getRootTimer()); it != end_timer_tree(); ++it) { - LLTrace::PeriodicRecording& frame_recording = LLTrace::get_frame_recording(); TimeBlock* timerp = (*it); - LLUnit total_time_ms = frame_recording.getLastRecordingPeriod().getSum(*timerp); - U32 num_calls = frame_recording.getLastRecordingPeriod().getSum(timerp->callCount()); + LLUnit 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() << " " @@ -505,7 +455,11 @@ void TimeBlock::writeLog(std::ostream& os) TimeBlockAccumulator::TimeBlockAccumulator() : mSelfTimeCounter(0), mTotalTimeCounter(0), - mCalls(0) + mCalls(0), + mLastCaller(NULL), + mActiveCount(0), + mMoveUpTree(false), + mParent(NULL) {} void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other ) @@ -513,6 +467,10 @@ void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other ) mSelfTimeCounter += other.mSelfTimeCounter; mTotalTimeCounter += other.mTotalTimeCounter; mCalls += other.mCalls; + mLastCaller = other.mLastCaller; + mActiveCount = other.mActiveCount; + mMoveUpTree = other.mMoveUpTree; + mParent = other.mParent; } void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other ) @@ -522,10 +480,4 @@ void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other ) mCalls = 0; } -TimeBlockTreeNode::TimeBlockTreeNode() -: mLastCaller(NULL), - mActiveCount(0), - mMoveUpTree(false) -{} - } // namespace LLTrace -- cgit v1.2.3 From 013f04cabec8e110ee659d9b3f75a4d25f114b7b Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Fri, 21 Dec 2012 00:13:21 -0800 Subject: SH-3468 WIP add memory tracking base class improvements on lifetime of lltrace core data structures tweaks to thread local pointer handling so that static constructors/destructors can safely call functions that use lltrace --- indra/llcommon/llfasttimer.cpp | 93 +++++++++++++----------------------------- 1 file changed, 29 insertions(+), 64 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index f4fa8f1e61..7c90b946af 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -35,6 +35,7 @@ #include "llunit.h" #include "llsd.h" #include "lltracerecording.h" +#include "lltracethreadrecorder.h" #include #include @@ -167,52 +168,16 @@ U64 TimeBlock::countsPerSecond() // counts per second for the *64-bit* timer TimeBlock::TimeBlock(const char* name, bool open, TimeBlock* parent) : TraceType(name), - mCollapsed(true), - mParent(NULL), - mNeedsSorting(false) + mCollapsed(true) { setCollapsed(!open); - - if (parent) - { - setParent(parent); - } - else - { - mParent = this; - } } -void TimeBlock::setParent(TimeBlock* parent) +TimeBlockTreeNode& TimeBlock::getTreeNode() const { - 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& children = mParent->getChildren(); - std::vector::iterator found_it = std::find(children.begin(), children.end(), this); - if (found_it != children.end()) - { - children.erase(found_it); - } - } - - mParent = parent; - if (parent) - { - parent->getChildren().push_back(this); - parent->mNeedsSorting = true; - } + TimeBlockTreeNode* nodep = LLTrace::get_thread_recorder()->getTimeBlockTreeNode(getIndex()); + llassert(nodep); + return *nodep; } // static @@ -232,17 +197,17 @@ void TimeBlock::processTimes() // bootstrap tree construction by attaching to last timer to be on stack // when this timer was called - if (timer.mParent == &TimeBlock::getRootTimer()) + if (timer.getParent() == &TimeBlock::getRootTimer()) { - TimeBlockAccumulator& accumulator = timer.getPrimaryAccumulator(); + TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator(); - if (accumulator.mLastCaller) + if (accumulator->mLastCaller) { - timer.setParent(accumulator.mLastCaller); - accumulator.mParent = accumulator.mLastCaller; + 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; + accumulator->mMoveUpTree = false; } } @@ -256,25 +221,25 @@ void TimeBlock::processTimes() TimeBlock* timerp = *it; // sort timers by time last called, so call graph makes sense - if (timerp->mNeedsSorting) + if (timerp->getTreeNode().mNeedsSorting) { - std::sort(timerp->getChildren().begin(), timerp->getChildren().end(), SortTimerByName()); + std::sort(timerp->beginChildren(), timerp->endChildren(), SortTimerByName()); } // skip root timer if (timerp != &TimeBlock::getRootTimer()) { - TimeBlockAccumulator& accumulator = timerp->getPrimaryAccumulator(); + TimeBlockAccumulator* accumulator = timerp->getPrimaryAccumulator(); - if (accumulator.mMoveUpTree) + if (accumulator->mMoveUpTree) { // 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()); - accumulator.mParent = timerp->mParent; - accumulator.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 @@ -286,15 +251,15 @@ void TimeBlock::processTimes() // walk up stack of active timers and accumulate current time while leaving timing structures active BlockTimer* cur_timer = cur_data->mCurTimer; - TimeBlockAccumulator& accumulator = cur_data->mTimerData->getPrimaryAccumulator(); + TimeBlockAccumulator* accumulator = cur_data->mTimerData->getPrimaryAccumulator(); // root defined by parent pointing to self while(cur_timer && cur_timer->mLastTimerData.mCurTimer != cur_timer) { U64 cumulative_time_delta = cur_time - cur_timer->mStartTime; U64 self_time_delta = cumulative_time_delta - cur_data->mChildTime; cur_data->mChildTime = 0; - accumulator.mSelfTimeCounter += self_time_delta; - accumulator.mTotalTimeCounter += cumulative_time_delta; + accumulator->mSelfTimeCounter += self_time_delta; + accumulator->mTotalTimeCounter += cumulative_time_delta; cur_timer->mStartTime = cur_time; @@ -316,10 +281,10 @@ void TimeBlock::processTimes() ++it) { TimeBlock& timer = *it; - TimeBlockAccumulator& accumulator = timer.getPrimaryAccumulator(); + TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator(); - accumulator.mLastCaller = NULL; - accumulator.mMoveUpTree = false; + accumulator->mLastCaller = NULL; + accumulator->mMoveUpTree = false; } // traverse tree in DFS post order, or bottom up @@ -338,19 +303,19 @@ void TimeBlock::processTimes() } -std::vector::const_iterator TimeBlock::beginChildren() +std::vector::iterator TimeBlock::beginChildren() { - return mChildren.begin(); + return getTreeNode().mChildren.begin(); } -std::vector::const_iterator TimeBlock::endChildren() +std::vector::iterator TimeBlock::endChildren() { - return mChildren.end(); + return getTreeNode().mChildren.end(); } std::vector& TimeBlock::getChildren() { - return mChildren; + return getTreeNode().mChildren; } //static -- cgit v1.2.3 From cda2cdda511eb2f7a58e284db2c852fd4a3808ae Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Thu, 3 Jan 2013 00:30:54 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system made fast timer stack thread local added LLThreadLocalSingleton made LLThreadLocalPointer obey pointer rules for const added LLThreadLocalSingletonPointer for fast thread local pointers --- indra/llcommon/llfasttimer.cpp | 41 ++++++++++++++++++++--------------------- 1 file changed, 20 insertions(+), 21 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 7c90b946af..ad8cf7296e 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -70,8 +70,6 @@ U64 TimeBlock::sClockResolution = 1000000000; // Nanosecond resolution U64 TimeBlock::sClockResolution = 1000000; // Microsecond resolution #endif -LLThreadLocalPointer TimeBlock::sCurTimerData; - static LLMutex* sLogLock = NULL; static std::queue sLogQueue; @@ -118,7 +116,7 @@ struct SortTimerByName } }; -TimeBlock& TimeBlock::getRootTimer() +TimeBlock& TimeBlock::getRootTimeBlock() { static TimeBlock root_timer("root", true, NULL); return root_timer; @@ -185,7 +183,7 @@ void TimeBlock::processTimes() { get_clock_count(); // good place to calculate clock frequency U64 cur_time = getCPUClockCount64(); - CurTimerData* cur_data = sCurTimerData.get(); + BlockTimerStackRecord* stack_record = ThreadTimerStack::getInstance(); // set up initial tree for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), end_it = LLInstanceTracker::endInstances(); @@ -193,11 +191,11 @@ void TimeBlock::processTimes() ++it) { TimeBlock& timer = *it; - if (&timer == &TimeBlock::getRootTimer()) continue; + if (&timer == &TimeBlock::getRootTimeBlock()) continue; // bootstrap tree construction by attaching to last timer to be on stack // when this timer was called - if (timer.getParent() == &TimeBlock::getRootTimer()) + if (timer.getParent() == &TimeBlock::getRootTimeBlock()) { TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator(); @@ -214,20 +212,21 @@ void TimeBlock::processTimes() // 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(TimeBlock::getRootTimer()); + for(timer_tree_bottom_up_iterator_t it = begin_timer_tree_bottom_up(TimeBlock::getRootTimeBlock()); it != end_timer_tree_bottom_up(); ++it) { TimeBlock* timerp = *it; // sort timers by time last called, so call graph makes sense - if (timerp->getTreeNode().mNeedsSorting) + TimeBlockTreeNode& tree_node = timerp->getTreeNode(); + if (tree_node.mNeedsSorting) { - std::sort(timerp->beginChildren(), timerp->endChildren(), SortTimerByName()); + std::sort(tree_node.mChildren.begin(), tree_node.mChildren.end(), SortTimerByName()); } // skip root timer - if (timerp != &TimeBlock::getRootTimer()) + if (timerp != &TimeBlock::getRootTimeBlock()) { TimeBlockAccumulator* accumulator = timerp->getPrimaryAccumulator(); @@ -250,27 +249,27 @@ void TimeBlock::processTimes() } // walk up stack of active timers and accumulate current time while leaving timing structures active - BlockTimer* cur_timer = cur_data->mCurTimer; - TimeBlockAccumulator* accumulator = cur_data->mTimerData->getPrimaryAccumulator(); + BlockTimer* cur_timer = stack_record->mActiveTimer; + TimeBlockAccumulator* accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); // root defined by parent pointing to self - while(cur_timer && cur_timer->mLastTimerData.mCurTimer != cur_timer) + while(cur_timer && cur_timer->mLastTimerData.mActiveTimer != cur_timer) { U64 cumulative_time_delta = cur_time - cur_timer->mStartTime; - U64 self_time_delta = cumulative_time_delta - cur_data->mChildTime; - cur_data->mChildTime = 0; + U64 self_time_delta = cumulative_time_delta - stack_record->mChildTime; + stack_record->mChildTime = 0; accumulator->mSelfTimeCounter += self_time_delta; accumulator->mTotalTimeCounter += cumulative_time_delta; cur_timer->mStartTime = cur_time; - cur_data = &cur_timer->mLastTimerData; - cur_data->mChildTime += cumulative_time_delta; - if (cur_data->mTimerData) + stack_record = &cur_timer->mLastTimerData; + stack_record->mChildTime += cumulative_time_delta; + if (stack_record->mTimeBlock) { - accumulator = cur_data->mTimerData->getPrimaryAccumulator(); + accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); } - cur_timer = cur_timer->mLastTimerData.mCurTimer; + cur_timer = cur_timer->mLastTimerData.mActiveTimer; } @@ -374,7 +373,7 @@ void TimeBlock::dumpCurTimes() 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(TimeBlock::getRootTimer()); + for(timer_tree_dfs_iterator_t it = begin_timer_tree(TimeBlock::getRootTimeBlock()); it != end_timer_tree(); ++it) { -- cgit v1.2.3 From cf8fa1a958f8676a0911bac7bdb950a865b58c83 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Fri, 4 Jan 2013 15:57:28 -0800 Subject: SH-3468 WIP add memory tracking base class further compile error fixes --- indra/llcommon/llfasttimer.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index ad8cf7296e..e6233a094e 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -137,12 +137,12 @@ void TimeBlock::setLogLock(LLMutex* lock) //static #if (LL_DARWIN || LL_LINUX || LL_SOLARIS) && !(defined(__i386__) || defined(__amd64__)) -U64 TimeBlock::countsPerSecond() // counts per second for the *64-bit* timer +U64 TimeBlock::countsPerSecond() { return sClockResolution; } #else // windows or x86-mac or x86-linux or x86-solaris -U64 TimeBlock::countsPerSecond() // counts per second for the *64-bit* timer +U64 TimeBlock::countsPerSecond() { #if LL_FASTTIMER_USE_RDTSC || !LL_WINDOWS //getCPUFrequency returns MHz and sCPUClockFrequency wants to be in Hz @@ -165,7 +165,7 @@ U64 TimeBlock::countsPerSecond() // counts per second for the *64-bit* timer #endif TimeBlock::TimeBlock(const char* name, bool open, TimeBlock* parent) -: TraceType(name), +: TraceType(name), mCollapsed(true) { setCollapsed(!open); -- cgit v1.2.3 From 20b2fa4052ae6789ec8894f33f4764a1f7233b24 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Mon, 14 Jan 2013 23:08:01 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system improved performance of fast timer stat gathering --- indra/llcommon/llfasttimer.cpp | 28 ++++++++++++++-------------- 1 file changed, 14 insertions(+), 14 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index e6233a094e..37332da31c 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -199,10 +199,11 @@ void TimeBlock::processTimes() { TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator(); - if (accumulator->mLastCaller) + if (accumulator->mLastAccumulator) { - timer.setParent(accumulator->mLastCaller); - accumulator->mParent = accumulator->mLastCaller; + TimeBlock* parent = accumulator->mLastAccumulator->mBlock; + timer.setParent(parent); + accumulator->mParent = parent; } // no need to push up tree on first use, flag can be set spuriously accumulator->mMoveUpTree = false; @@ -250,23 +251,22 @@ void TimeBlock::processTimes() // walk up stack of active timers and accumulate current time while leaving timing structures active BlockTimer* cur_timer = stack_record->mActiveTimer; - TimeBlockAccumulator* accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); + TimeBlockAccumulator* accumulator = stack_record->mAccumulator; // root defined by parent pointing to self while(cur_timer && cur_timer->mLastTimerData.mActiveTimer != cur_timer) { U64 cumulative_time_delta = cur_time - cur_timer->mStartTime; - U64 self_time_delta = cumulative_time_delta - stack_record->mChildTime; + accumulator->mChildTimeCounter += stack_record->mChildTime; stack_record->mChildTime = 0; - accumulator->mSelfTimeCounter += self_time_delta; accumulator->mTotalTimeCounter += cumulative_time_delta; cur_timer->mStartTime = cur_time; stack_record = &cur_timer->mLastTimerData; stack_record->mChildTime += cumulative_time_delta; - if (stack_record->mTimeBlock) + if (stack_record->mAccumulator) { - accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); + accumulator = stack_record->mAccumulator; } cur_timer = cur_timer->mLastTimerData.mActiveTimer; @@ -282,7 +282,7 @@ void TimeBlock::processTimes() TimeBlock& timer = *it; TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator(); - accumulator->mLastCaller = NULL; + accumulator->mLastAccumulator = NULL; accumulator->mMoveUpTree = false; } @@ -417,10 +417,10 @@ void TimeBlock::writeLog(std::ostream& os) ////////////////////////////////////////////////////////////////////////////////////////////////////////////////// TimeBlockAccumulator::TimeBlockAccumulator() -: mSelfTimeCounter(0), +: mChildTimeCounter(0), mTotalTimeCounter(0), mCalls(0), - mLastCaller(NULL), + mLastAccumulator(NULL), mActiveCount(0), mMoveUpTree(false), mParent(NULL) @@ -428,10 +428,10 @@ TimeBlockAccumulator::TimeBlockAccumulator() void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other ) { - mSelfTimeCounter += other.mSelfTimeCounter; + mChildTimeCounter += other.mChildTimeCounter; mTotalTimeCounter += other.mTotalTimeCounter; mCalls += other.mCalls; - mLastCaller = other.mLastCaller; + mLastAccumulator = other.mLastAccumulator; mActiveCount = other.mActiveCount; mMoveUpTree = other.mMoveUpTree; mParent = other.mParent; @@ -440,7 +440,7 @@ void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other ) void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other ) { mTotalTimeCounter = 0; - mSelfTimeCounter = 0; + mChildTimeCounter = 0; mCalls = 0; } -- cgit v1.2.3 From 43a92d01afdb4f1dd4003059b79f87e9687527a1 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Thu, 17 Jan 2013 20:11:43 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system fixed some uninitialized variables root timer accumulator was being initialized to NULL --- indra/llcommon/llfasttimer.cpp | 30 +++++++++++++++++------------- 1 file changed, 17 insertions(+), 13 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 37332da31c..b4a422816e 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -183,7 +183,6 @@ void TimeBlock::processTimes() { get_clock_count(); // good place to calculate clock frequency U64 cur_time = getCPUClockCount64(); - BlockTimerStackRecord* stack_record = ThreadTimerStack::getInstance(); // set up initial tree for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), end_it = LLInstanceTracker::endInstances(); @@ -202,6 +201,7 @@ void TimeBlock::processTimes() if (accumulator->mLastAccumulator) { TimeBlock* parent = accumulator->mLastAccumulator->mBlock; + llassert(parent); timer.setParent(parent); accumulator->mParent = parent; } @@ -250,26 +250,28 @@ void TimeBlock::processTimes() } // walk up stack of active timers and accumulate current time while leaving timing structures active - BlockTimer* cur_timer = stack_record->mActiveTimer; - TimeBlockAccumulator* accumulator = stack_record->mAccumulator; + BlockTimerStackRecord* stack_record = ThreadTimerStack::getInstance(); + BlockTimer* cur_timer = stack_record->mActiveTimer; + TimeBlockAccumulator* accumulator = stack_record->mAccumulator; + + llassert(accumulator); + // root defined by parent pointing to self - while(cur_timer && cur_timer->mLastTimerData.mActiveTimer != cur_timer) + while(cur_timer && cur_timer->mParentTimerData.mActiveTimer != cur_timer) { U64 cumulative_time_delta = cur_time - cur_timer->mStartTime; + + accumulator->mTotalTimeCounter += cumulative_time_delta; accumulator->mChildTimeCounter += stack_record->mChildTime; stack_record->mChildTime = 0; - accumulator->mTotalTimeCounter += cumulative_time_delta; cur_timer->mStartTime = cur_time; - stack_record = &cur_timer->mLastTimerData; - stack_record->mChildTime += cumulative_time_delta; - if (stack_record->mAccumulator) - { - accumulator = stack_record->mAccumulator; - } + stack_record = &cur_timer->mParentTimerData; + accumulator = stack_record->mAccumulator; + cur_timer = stack_record->mActiveTimer; - cur_timer = cur_timer->mLastTimerData.mActiveTimer; + stack_record->mChildTime += cumulative_time_delta; } @@ -423,7 +425,8 @@ TimeBlockAccumulator::TimeBlockAccumulator() mLastAccumulator(NULL), mActiveCount(0), mMoveUpTree(false), - mParent(NULL) + mParent(NULL), + mBlock(NULL) {} void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other ) @@ -435,6 +438,7 @@ void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other ) mActiveCount = other.mActiveCount; mMoveUpTree = other.mMoveUpTree; mParent = other.mParent; + mBlock = other.mBlock; } void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other ) -- cgit v1.2.3 From e975ae35ab57f56adfaed64bc108240a5013f040 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Fri, 18 Jan 2013 15:59:16 -0800 Subject: SH-3406 WIP convert fast timers to lltrace system fixed crash on startup --- indra/llcommon/llfasttimer.cpp | 26 ++++++++++---------------- 1 file changed, 10 insertions(+), 16 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index b4a422816e..ea4e1a89a2 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -198,12 +198,10 @@ void TimeBlock::processTimes() { TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator(); - if (accumulator->mLastAccumulator) + if (accumulator->mLastCaller) { - TimeBlock* parent = accumulator->mLastAccumulator->mBlock; - llassert(parent); - timer.setParent(parent); - accumulator->mParent = parent; + 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; @@ -252,10 +250,8 @@ void TimeBlock::processTimes() // walk up stack of active timers and accumulate current time while leaving timing structures active BlockTimerStackRecord* stack_record = ThreadTimerStack::getInstance(); BlockTimer* cur_timer = stack_record->mActiveTimer; - TimeBlockAccumulator* accumulator = stack_record->mAccumulator; - - llassert(accumulator); - + TimeBlockAccumulator* accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); + // root defined by parent pointing to self while(cur_timer && cur_timer->mParentTimerData.mActiveTimer != cur_timer) { @@ -268,7 +264,7 @@ void TimeBlock::processTimes() cur_timer->mStartTime = cur_time; stack_record = &cur_timer->mParentTimerData; - accumulator = stack_record->mAccumulator; + accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); cur_timer = stack_record->mActiveTimer; stack_record->mChildTime += cumulative_time_delta; @@ -284,7 +280,7 @@ void TimeBlock::processTimes() TimeBlock& timer = *it; TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator(); - accumulator->mLastAccumulator = NULL; + accumulator->mLastCaller = NULL; accumulator->mMoveUpTree = false; } @@ -422,11 +418,10 @@ TimeBlockAccumulator::TimeBlockAccumulator() : mChildTimeCounter(0), mTotalTimeCounter(0), mCalls(0), - mLastAccumulator(NULL), + mLastCaller(NULL), mActiveCount(0), mMoveUpTree(false), - mParent(NULL), - mBlock(NULL) + mParent(NULL) {} void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other ) @@ -434,11 +429,10 @@ void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other ) mChildTimeCounter += other.mChildTimeCounter; mTotalTimeCounter += other.mTotalTimeCounter; mCalls += other.mCalls; - mLastAccumulator = other.mLastAccumulator; + mLastCaller = other.mLastCaller; mActiveCount = other.mActiveCount; mMoveUpTree = other.mMoveUpTree; mParent = other.mParent; - mBlock = other.mBlock; } void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other ) -- cgit v1.2.3 From 3a555a2ff84d9b340e33673d7a03f37c966f06e6 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Thu, 24 Jan 2013 19:53:17 -0800 Subject: SH-3275 WIP interesting Update viewer metrics system to be more flexible removed LLFastTimerView::getFrameTimer() dead code elimination fixed off by one array access crash --- indra/llcommon/llfasttimer.cpp | 15 --------------- 1 file changed, 15 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index ea4e1a89a2..a144a8c94e 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -270,7 +270,6 @@ void TimeBlock::processTimes() stack_record->mChildTime += cumulative_time_delta; } - // reset for next frame for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), end_it = LLInstanceTracker::endInstances(); @@ -283,20 +282,6 @@ void TimeBlock::processTimes() accumulator->mLastCaller = NULL; accumulator->mMoveUpTree = false; } - - // traverse tree in DFS post order, or bottom up - //for(timer_tree_bottom_up_iterator_t it = begin_timer_tree_bottom_up(TimeBlock::getRootTimer()); - // it != end_timer_tree_bottom_up(); - // ++it) - //{ - // TimeBlock* timerp = (*it); - // TimeBlockAccumulator& accumulator = timerp->getPrimaryAccumulator(); - // timerp->mTreeTimeCounter = accumulator.mSelfTimeCounter; - // for (child_const_iter child_it = timerp->beginChildren(); child_it != timerp->endChildren(); ++child_it) - // { - // timerp->mTreeTimeCounter += (*child_it)->mTreeTimeCounter; - // } - //} } -- cgit v1.2.3 From 2c68d5367c5c44aceb4ff23d9672c35642e030f7 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Sun, 27 Jan 2013 21:35:20 -0800 Subject: SH-3275 WIP interesting Update viewer metrics system to be more flexible fixed memory leak fixed glitching of fast timer display --- indra/llcommon/llfasttimer.cpp | 7 +++++++ 1 file changed, 7 insertions(+) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index a144a8c94e..e58c5c0f98 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -425,6 +425,13 @@ void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other ) mTotalTimeCounter = 0; mChildTimeCounter = 0; mCalls = 0; + if (other) + { + mLastCaller = other->mLastCaller; + mActiveCount = other->mActiveCount; + mMoveUpTree = other->mMoveUpTree; + mParent = other->mParent; + } } } // namespace LLTrace -- cgit v1.2.3 From 438cbfe489cc34261ac600bbb22983164e59b1d9 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Thu, 7 Feb 2013 20:07:31 -0800 Subject: SH-3275 WIP interesting Update viewer metrics system to be more flexible fix for timings for recursive fast timers not being correct --- indra/llcommon/llfasttimer.cpp | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') 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) -- cgit v1.2.3 From e3700112f313f3570887047d5b56a661af0afac5 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Fri, 8 Feb 2013 00:03:31 -0800 Subject: SH-3275 WIP interesting Update viewer metrics system to be more flexible added debug output to BlockTimer --- indra/llcommon/llfasttimer.cpp | 8 ++++++++ 1 file changed, 8 insertions(+) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index e58c5c0f98..ba626bcc32 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -434,4 +434,12 @@ void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other ) } } +LLUnit BlockTimer::getElapsedTime() +{ + U64 total_time = TimeBlock::getCPUClockCount64() - mStartTime; + + return (F64)total_time / (F64)TimeBlock::countsPerSecond(); +} + + } // namespace LLTrace -- cgit v1.2.3 From 2e15e8fd4ba62204c76f6e2a91d3e50f62e6c1fc Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Sat, 9 Feb 2013 00:34:59 -0800 Subject: SH-3275 FIX interesting Update viewer metrics system to be more flexible fixed anamolous LLFastTimer timings --- indra/llcommon/llfasttimer.cpp | 28 +++++++++++++++++++++------- 1 file changed, 21 insertions(+), 7 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 4387218f5a..0ea91d7e51 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -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 BlockTimer::getElapsedTime() -- cgit v1.2.3 From 67ac6e7a294bd7401c55ed1d7423166dda1c0ee6 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Sun, 10 Feb 2013 23:53:45 -0800 Subject: SH-3275 FIX interesting Update viewer metrics system to be more flexible streamlined fast timer delta tracking --- indra/llcommon/llfasttimer.cpp | 30 ++++++++++++------------------ 1 file changed, 12 insertions(+), 18 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 0ea91d7e51..f8837a7085 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -256,16 +256,12 @@ void TimeBlock::processTimes() while(cur_timer && cur_timer->mParentTimerData.mActiveTimer != cur_timer) { U64 cumulative_time_delta = cur_time - cur_timer->mStartTime; - 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; + accumulator->mTotalTimeCounter += cumulative_time_delta - (accumulator->mTotalTimeCounter - accumulator->mStartTotalTimeCounter); + accumulator->mSelfTimeCounter += cumulative_time_delta - stack_record->mChildTime; stack_record->mChildTime = 0; cur_timer->mStartTime = cur_time; - cur_timer->mStartSelfTimeCounter = accumulator->mSelfTimeCounter; - cur_timer->mStartChildTimeCounter = accumulator->mChildTimeCounter; + cur_timer->mStartTotalTimeCounter = accumulator->mTotalTimeCounter; stack_record = &cur_timer->mParentTimerData; accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); @@ -404,10 +400,9 @@ void TimeBlock::writeLog(std::ostream& os) ////////////////////////////////////////////////////////////////////////////////////////////////////////////////// TimeBlockAccumulator::TimeBlockAccumulator() -: mChildTimeCounter(0), +: mTotalTimeCounter(0), mSelfTimeCounter(0), - mStartChildTimeCounter(0), - mStartSelfTimeCounter(0), + mStartTotalTimeCounter(0), mCalls(0), mLastCaller(NULL), mActiveCount(0), @@ -417,8 +412,8 @@ TimeBlockAccumulator::TimeBlockAccumulator() void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other ) { - mChildTimeCounter += other.mChildTimeCounter - other.mStartChildTimeCounter; - mSelfTimeCounter += other.mSelfTimeCounter - other.mStartSelfTimeCounter; + mTotalTimeCounter += other.mTotalTimeCounter - other.mStartTotalTimeCounter; + mSelfTimeCounter += other.mSelfTimeCounter; mCalls += other.mCalls; mLastCaller = other.mLastCaller; mActiveCount = other.mActiveCount; @@ -429,12 +424,12 @@ void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other ) void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other ) { mCalls = 0; + mSelfTimeCounter = 0; + if (other) { - mStartSelfTimeCounter = other->mSelfTimeCounter; - mSelfTimeCounter = mStartSelfTimeCounter; - mStartChildTimeCounter = other->mChildTimeCounter; - mChildTimeCounter = mStartChildTimeCounter; + mStartTotalTimeCounter = other->mTotalTimeCounter; + mTotalTimeCounter = mStartTotalTimeCounter; mLastCaller = other->mLastCaller; mActiveCount = other->mActiveCount; @@ -443,8 +438,7 @@ void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other ) } else { - mStartSelfTimeCounter = mSelfTimeCounter; - mStartChildTimeCounter = mChildTimeCounter; + mStartTotalTimeCounter = mTotalTimeCounter; } } -- cgit v1.2.3 From a6bb68b6e530df91d03abfc062c700ebc4e856aa Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Wed, 13 Feb 2013 15:21:20 -0800 Subject: SH-3275 FIX interesting Update viewer metrics system to be more flexible fix for inaccurate optimization of full block time calculations --- indra/llcommon/llfasttimer.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index f8837a7085..5baf049c03 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -256,12 +256,12 @@ void TimeBlock::processTimes() while(cur_timer && cur_timer->mParentTimerData.mActiveTimer != cur_timer) { U64 cumulative_time_delta = cur_time - cur_timer->mStartTime; - accumulator->mTotalTimeCounter += cumulative_time_delta - (accumulator->mTotalTimeCounter - accumulator->mStartTotalTimeCounter); + 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->mStartTotalTimeCounter = accumulator->mTotalTimeCounter; + cur_timer->mBlockStartTotalTimeCounter = accumulator->mTotalTimeCounter; stack_record = &cur_timer->mParentTimerData; accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); @@ -376,7 +376,7 @@ void TimeBlock::dumpCurTimes() } out_str << timerp->getName() << " " - << std::setprecision(3) << total_time_ms.as().value() << " ms, " + << std::setprecision(3) << total_time_ms.as().value() << " ms, " << num_calls << " calls"; llinfos << out_str.str() << llendl; -- cgit v1.2.3 From cd46f3d08cef6f43c29447e36c920d10ec184a18 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Mon, 25 Mar 2013 20:21:04 -0700 Subject: BUILDFIX gcc fix --- indra/llcommon/llfasttimer.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index fbffe133f1..b40aec4886 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -185,7 +185,7 @@ void TimeBlock::processTimes() U64 cur_time = getCPUClockCount64(); // set up initial tree - for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), end_it = LLInstanceTracker::endInstances(); + for (LLInstanceTracker::instance_iter begin_it = LLInstanceTracker::beginInstances(), end_it = LLInstanceTracker::endInstances(), it = begin_it; it != end_it; ++it) { -- cgit v1.2.3 From 07ca6fce7c9cffe1b8f215f25bb826fedf57a5b7 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Wed, 10 Apr 2013 21:51:56 -0700 Subject: SH-3931 WIP Interesting: Add graphs to visualize scene load metrics removed PeriodicRecording::getTotalRecording as it was showing up at the top on the profiler renamed getPrevRecordingPeriod, etc. to getPrevRecording --- indra/llcommon/llfasttimer.cpp | 13 ++++++++----- 1 file changed, 8 insertions(+), 5 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index fbffe133f1..a7adcc6729 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -176,11 +176,14 @@ TimeBlockTreeNode& TimeBlock::getTreeNode() const TimeBlockTreeNode* nodep = LLTrace::get_thread_recorder()->getTimeBlockTreeNode(getIndex()); llassert(nodep); return *nodep; - } +} + +static LLFastTimer::DeclareTimer FTM_PROCESS_TIMES("Process FastTimer Times"); //static void TimeBlock::processTimes() { + LLFastTimer _(FTM_PROCESS_TIMES); get_clock_count(); // good place to calculate clock frequency U64 cur_time = getCPUClockCount64(); @@ -329,12 +332,12 @@ void TimeBlock::logStats() { 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())); + sd[timer.getName()]["Time"] = (LLSD::Real) (frame_recording.getLastRecording().getSum(timer).value()); + sd[timer.getName()]["Calls"] = (LLSD::Integer) (frame_recording.getLastRecording().getSum(timer.callCount())); // computing total time here because getting the root timer's getCountHistory // doesn't work correctly on the first frame - total_time += frame_recording.getLastRecordingPeriod().getSum(timer); + total_time += frame_recording.getLastRecording().getSum(timer); } } @@ -353,7 +356,7 @@ void TimeBlock::logStats() void TimeBlock::dumpCurTimes() { LLTrace::PeriodicRecording& frame_recording = LLTrace::get_frame_recording(); - LLTrace::Recording& last_frame_recording = frame_recording.getLastRecordingPeriod(); + LLTrace::Recording& last_frame_recording = frame_recording.getLastRecording(); // walk over timers in depth order and output timings for(timer_tree_dfs_iterator_t it = begin_timer_tree(TimeBlock::getRootTimeBlock()); -- cgit v1.2.3 From e50e6004082223fdc0bfd78bc697d48a7f45b379 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Thu, 30 May 2013 20:15:48 -0700 Subject: SH-3931 WIP Interesting: Add graphs to visualize scene load metrics reverted SlaveThreadRecorder update gating moved processTimes() outside of Recording, so it is called only once per frame refined sample merge logic so that multi-threaded samples do not stomp on linear history of a stat --- indra/llcommon/llfasttimer.cpp | 40 ++++++++++++++++++++++------------------ 1 file changed, 22 insertions(+), 18 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 5dc5fdd5be..3fdd33959d 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -180,6 +180,7 @@ TimeBlockTreeNode& TimeBlock::getTreeNode() const static LLFastTimer::DeclareTimer FTM_PROCESS_TIMES("Process FastTimer Times"); +// not thread safe, so only call on main thread //static void TimeBlock::processTimes() { @@ -195,8 +196,8 @@ void TimeBlock::processTimes() 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 + // bootstrap tree construction by attaching to last timer to be on stack + // when this timer was called if (timer.getParent() == &TimeBlock::getRootTimeBlock()) { TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator(); @@ -233,30 +234,30 @@ void TimeBlock::processTimes() TimeBlockAccumulator* accumulator = timerp->getPrimaryAccumulator(); if (accumulator->mMoveUpTree) - { + { // 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()); - 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(); + //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()); + 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(); + } } } -} // walk up stack of active timers and accumulate current time while leaving timing structures active BlockTimerStackRecord* stack_record = ThreadTimerStack::getInstance(); BlockTimer* cur_timer = stack_record->mActiveTimer; TimeBlockAccumulator* accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); - // root defined by parent pointing to self - while(cur_timer && cur_timer->mParentTimerData.mActiveTimer != cur_timer) + while(cur_timer + && cur_timer->mParentTimerData.mActiveTimer != cur_timer) // root defined by parent pointing to self { U64 cumulative_time_delta = cur_time - cur_timer->mStartTime; accumulator->mTotalTimeCounter += cumulative_time_delta - (accumulator->mTotalTimeCounter - cur_timer->mBlockStartTotalTimeCounter); @@ -413,8 +414,11 @@ TimeBlockAccumulator::TimeBlockAccumulator() mParent(NULL) {} -void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other ) +void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other, bool append ) { + // we can't merge two unrelated time block samples, as that will screw with the nested timings + // due to the call hierarchy of each thread + llassert(append); mTotalTimeCounter += other.mTotalTimeCounter - other.mStartTotalTimeCounter; mSelfTimeCounter += other.mSelfTimeCounter; mCalls += other.mCalls; -- cgit v1.2.3 From 9fd3af3c389ed491b515cbb5136b344b069913e4 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Thu, 13 Jun 2013 15:29:15 -0700 Subject: SH-3931 WIP Interesting: Add graphs to visualize scene load metrics changed Units macros and argument order to make it more clear optimized units for integer types fixed merging of periodicrecordings...should eliminate duplicate entries in sceneloadmonitor history --- indra/llcommon/llfasttimer.cpp | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index dfc72bd2ce..809a0327ca 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -146,8 +146,8 @@ U64 TimeBlock::countsPerSecond() { #if LL_FASTTIMER_USE_RDTSC || !LL_WINDOWS //getCPUFrequency returns MHz and sCPUClockFrequency wants to be in Hz - static LLUnit sCPUClockFrequency = LLProcessorInfo().getCPUFrequency(); - + static LLUnit sCPUClockFrequency = LLProcessorInfo().getCPUFrequency(); + return sCPUClockFrequency.value(); #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()) @@ -159,8 +159,8 @@ U64 TimeBlock::countsPerSecond() QueryPerformanceFrequency((LARGE_INTEGER*)&sCPUClockFrequency); firstcall = false; } -#endif return sCPUClockFrequency.value(); +#endif } #endif @@ -318,11 +318,11 @@ void TimeBlock::logStats() 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()) / (LLUnit(LLProcessorInfo().getCPUFrequency())) << LL_ENDL; + LL_DEBUGS("FastTimers") << "elapsed sec " << ((F64)getCPUClockCount64()) / (LLUnit(LLProcessorInfo().getCPUFrequency())) << LL_ENDL; } call_count++; - LLUnit total_time(0); + LLUnit total_time(0); LLSD sd; { @@ -365,7 +365,7 @@ void TimeBlock::dumpCurTimes() ++it) { TimeBlock* timerp = (*it); - LLUnit total_time_ms = last_frame_recording.getSum(*timerp); + LLUnit 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 @@ -449,7 +449,7 @@ void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other ) } } -LLUnit BlockTimer::getElapsedTime() +LLUnit BlockTimer::getElapsedTime() { U64 total_time = TimeBlock::getCPUClockCount64() - mStartTime; -- cgit v1.2.3 From 3f2de87340b1c831ea59e4a3ca960d49f343c9fd Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Mon, 17 Jun 2013 01:18:21 -0700 Subject: SH-3931 WIP Interesting: Add graphs to visualize scene load metrics added getAs and setAs to LLUnit to make it clearer how you specify units removed accidental 0-based indexing of periodicRecording history... should now be consistently 1-based, with 0 accessing current active recording removed per frame timer updates of all historical timer bars in fast timer display added missing assignment operator to recordings --- indra/llcommon/llfasttimer.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 809a0327ca..d9670891f8 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -365,11 +365,11 @@ void TimeBlock::dumpCurTimes() ++it) { TimeBlock* timerp = (*it); - LLUnit total_time_ms = last_frame_recording.getSum(*timerp); + LLUnit total_time = 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; + if (total_time < LLUnit(0.1)) continue; std::ostringstream out_str; TimeBlock* parent_timerp = timerp; @@ -380,7 +380,7 @@ void TimeBlock::dumpCurTimes() } out_str << timerp->getName() << " " - << std::setprecision(3) << total_time_ms.as().value() << " ms, " + << std::setprecision(3) << total_time.getAs() << " ms, " << num_calls << " calls"; llinfos << out_str.str() << llendl; -- cgit v1.2.3 From d136c4c29686c565b5a46503aa67a9c958b4145d Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Tue, 18 Jun 2013 23:41:53 -0700 Subject: SH-4246 FIX interesting: fast timers significantly decreases framerate removed implicit flushes on reads from recorders for better performance made sure stack timers were updated on recorder deactivate faster rendering and better ui for fast timer view --- indra/llcommon/llfasttimer.cpp | 77 ++++++++++++++++++++++++++---------------- 1 file changed, 48 insertions(+), 29 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index d9670891f8..4da9c3fd6c 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -178,43 +178,38 @@ TimeBlockTreeNode& TimeBlock::getTreeNode() const return *nodep; } -static LLFastTimer::DeclareTimer FTM_PROCESS_TIMES("Process FastTimer Times"); -// not thread safe, so only call on main thread -//static -void TimeBlock::processTimes() +void TimeBlock::bootstrapTimerTree() { - LLFastTimer _(FTM_PROCESS_TIMES); - get_clock_count(); // good place to calculate clock frequency - U64 cur_time = getCPUClockCount64(); - - // set up initial tree for (LLInstanceTracker::instance_iter begin_it = LLInstanceTracker::beginInstances(), end_it = LLInstanceTracker::endInstances(), it = begin_it; it != end_it; ++it) { 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.getParent() == &TimeBlock::getRootTimeBlock()) { TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator(); - + if (accumulator->mLastCaller) { timer.setParent(accumulator->mLastCaller); accumulator->mParent = accumulator->mLastCaller; } - // no need to push up tree on first use, flag can be set spuriously + // no need to push up tree on first use, flag can be set spuriously accumulator->mMoveUpTree = false; } } +} - // 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 +// 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 +void TimeBlock::incrementalUpdateTimerTree() +{ for(timer_tree_bottom_up_iterator_t it = begin_timer_tree_bottom_up(TimeBlock::getRootTimeBlock()); it != end_timer_tree_bottom_up(); ++it) @@ -240,27 +235,35 @@ void TimeBlock::processTimes() 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()); - accumulator->mParent = timerp->getParent(); - accumulator->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 + // as ancestors may call this timer only on certain paths, so we want to resolve + // child-most block locations before their parents it.skipAncestors(); } } } +} + + +void TimeBlock::updateTimes() +{ + U64 cur_time = getCPUClockCount64(); // walk up stack of active timers and accumulate current time while leaving timing structures active - BlockTimerStackRecord* stack_record = ThreadTimerStack::getInstance(); - BlockTimer* cur_timer = stack_record->mActiveTimer; - TimeBlockAccumulator* accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); + BlockTimerStackRecord* stack_record = ThreadTimerStack::getInstance(); + BlockTimer* cur_timer = stack_record->mActiveTimer; + TimeBlockAccumulator* accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); while(cur_timer && cur_timer->mParentTimerData.mActiveTimer != cur_timer) // root defined by parent pointing to self { U64 cumulative_time_delta = cur_time - cur_timer->mStartTime; - accumulator->mTotalTimeCounter += cumulative_time_delta - (accumulator->mTotalTimeCounter - cur_timer->mBlockStartTotalTimeCounter); + accumulator->mTotalTimeCounter += cumulative_time_delta + - (accumulator->mTotalTimeCounter + - cur_timer->mBlockStartTotalTimeCounter); accumulator->mSelfTimeCounter += cumulative_time_delta - stack_record->mChildTime; stack_record->mChildTime = 0; @@ -268,11 +271,28 @@ void TimeBlock::processTimes() cur_timer->mBlockStartTotalTimeCounter = accumulator->mTotalTimeCounter; stack_record = &cur_timer->mParentTimerData; - accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); - cur_timer = stack_record->mActiveTimer; + accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); + cur_timer = stack_record->mActiveTimer; stack_record->mChildTime += cumulative_time_delta; } +} + +static LLFastTimer::DeclareTimer FTM_PROCESS_TIMES("Process FastTimer Times"); + +// not thread safe, so only call on main thread +//static +void TimeBlock::processTimes() +{ + LLFastTimer _(FTM_PROCESS_TIMES); + get_clock_count(); // good place to calculate clock frequency + + // set up initial tree + bootstrapTimerTree(); + + incrementalUpdateTimerTree(); + + updateTimes(); // reset for next frame for (LLInstanceTracker::instance_iter it = LLInstanceTracker::beginInstances(), @@ -288,14 +308,13 @@ void TimeBlock::processTimes() } } - std::vector::iterator TimeBlock::beginChildren() - { +{ return getTreeNode().mChildren.begin(); - } +} std::vector::iterator TimeBlock::endChildren() - { +{ return getTreeNode().mChildren.end(); } -- cgit v1.2.3 From c5fc8f90060aa7a6c8fbb72313172423b01eddc5 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Wed, 19 Jun 2013 08:23:53 -0700 Subject: SH-4246 FIX interesting: fast timers significantly decreases framerate moved collapsed flag to fast timer tree node --- indra/llcommon/llfasttimer.cpp | 8 +++----- 1 file changed, 3 insertions(+), 5 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 4da9c3fd6c..becfa9c288 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -118,7 +118,7 @@ struct SortTimerByName TimeBlock& TimeBlock::getRootTimeBlock() { - static TimeBlock root_timer("root", true, NULL); + static TimeBlock root_timer("root", NULL); return root_timer; } @@ -164,11 +164,9 @@ U64 TimeBlock::countsPerSecond() } #endif -TimeBlock::TimeBlock(const char* name, bool open, TimeBlock* parent) -: TraceType(name), - mCollapsed(true) +TimeBlock::TimeBlock(const char* name, TimeBlock* parent) +: TraceType(name) { - setCollapsed(!open); } TimeBlockTreeNode& TimeBlock::getTreeNode() const -- cgit v1.2.3 From ffa7123bb5187e1da491a8f475d696053d9c9ee4 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Fri, 28 Jun 2013 20:45:20 -0700 Subject: SH-4299 FIX Interesting: High fps shown temporarily off scale in statistics console added ability to force uniqueness of LLCopyOnWritePointer converted more variables to units added convenience function for unit constants --- indra/llcommon/llfasttimer.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 60c451b137..23e27622bf 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -386,7 +386,7 @@ void TimeBlock::dumpCurTimes() U32 num_calls = last_frame_recording.getSum(timerp->callCount()); // Don't bother with really brief times, keep output concise - if (total_time < LLUnit(0.1)) continue; + if (total_time < LLUnits::Milliseconds::fromValue(0.1f)) continue; std::ostringstream out_str; TimeBlock* parent_timerp = timerp; @@ -397,7 +397,7 @@ void TimeBlock::dumpCurTimes() } out_str << timerp->getName() << " " - << std::setprecision(3) << total_time.getAs() << " ms, " + << std::setprecision(3) << total_time.valueAs() << " ms, " << num_calls << " calls"; llinfos << out_str.str() << llendl; -- cgit v1.2.3 From 2fc422f39ddaca25c69e8cf2092a9d66840379f3 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Sun, 30 Jun 2013 13:32:34 -0700 Subject: fixed memory leak due to implementation of LLThreadLocalSingleton removed LLThreadLocalSingleton collapsed all thread recorder classes to single type, LLTrace::ThreadRecorder moved fasttimer stack head to llthreadlocalsingletonpointer via ThreadRecorder --- indra/llcommon/llfasttimer.cpp | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 23e27622bf..7a7f1c79c1 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -247,17 +247,18 @@ void TimeBlock::incrementalUpdateTimerTree() void TimeBlock::updateTimes() - { - U64 cur_time = getCPUClockCount64(); - +{ // walk up stack of active timers and accumulate current time while leaving timing structures active - BlockTimerStackRecord* stack_record = ThreadTimerStack::getInstance(); + BlockTimerStackRecord* stack_record = LLThreadLocalSingletonPointer::getInstance(); + if (stack_record) return; + + U64 cur_time = getCPUClockCount64(); BlockTimer* cur_timer = stack_record->mActiveTimer; TimeBlockAccumulator* accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); while(cur_timer && cur_timer->mParentTimerData.mActiveTimer != cur_timer) // root defined by parent pointing to self - { + { U64 cumulative_time_delta = cur_time - cur_timer->mStartTime; accumulator->mTotalTimeCounter += cumulative_time_delta - (accumulator->mTotalTimeCounter -- cgit v1.2.3 From 04bdc8ba83c297945dd60489c241b88adf892ff4 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Mon, 1 Jul 2013 17:04:01 -0700 Subject: SH-4294 FIX Interesting: Statistics Texture cache hit rate is always 0% also, removed LLTrace::init and cleanup removed derived class implementation of memory stat for LLMemTrackable is automatic now --- indra/llcommon/llfasttimer.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 7a7f1c79c1..a72f16d385 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -250,7 +250,7 @@ void TimeBlock::updateTimes() { // walk up stack of active timers and accumulate current time while leaving timing structures active BlockTimerStackRecord* stack_record = LLThreadLocalSingletonPointer::getInstance(); - if (stack_record) return; + if (!stack_record) return; U64 cur_time = getCPUClockCount64(); BlockTimer* cur_timer = stack_record->mActiveTimer; -- cgit v1.2.3 From 862cdf3061d66dfe4ae482f24436960b136a3ce4 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Thu, 18 Jul 2013 15:08:46 -0700 Subject: SH-4297 WIP interesting: viewer-interesting starts loading cached scene late fixed ostream precision munging in llsys --- indra/llcommon/llfasttimer.cpp | 67 +++++++++++++++++++++--------------------- 1 file changed, 33 insertions(+), 34 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index a72f16d385..79aa0c8722 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -117,22 +117,22 @@ struct SortTimerByName }; TimeBlock& TimeBlock::getRootTimeBlock() - { +{ static TimeBlock root_timer("root", NULL); return root_timer; - } +} void TimeBlock::pushLog(LLSD log) - { +{ LLMutexLock lock(sLogLock); sLogQueue.push(log); - } +} void TimeBlock::setLogLock(LLMutex* lock) - { +{ sLogLock = lock; - } +} //static @@ -166,8 +166,7 @@ U64 TimeBlock::countsPerSecond() TimeBlock::TimeBlock(const char* name, TimeBlock* parent) : TraceType(name) -{ -} +{} TimeBlockTreeNode& TimeBlock::getTreeNode() const { @@ -182,7 +181,7 @@ void TimeBlock::bootstrapTimerTree() for (LLInstanceTracker::instance_iter begin_it = LLInstanceTracker::beginInstances(), end_it = LLInstanceTracker::endInstances(), it = begin_it; it != end_it; ++it) - { + { TimeBlock& timer = *it; if (&timer == &TimeBlock::getRootTimeBlock()) continue; @@ -193,13 +192,13 @@ void TimeBlock::bootstrapTimerTree() TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator(); if (accumulator->mLastCaller) - { + { 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; -} + } } } @@ -217,32 +216,32 @@ void TimeBlock::incrementalUpdateTimerTree() // 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 != &TimeBlock::getRootTimeBlock()) - { + { TimeBlockAccumulator* accumulator = timerp->getPrimaryAccumulator(); if (accumulator->mMoveUpTree) - { - // 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()); - 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(); + { + // 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()); + 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(); + } } } - } } @@ -308,12 +307,12 @@ void TimeBlock::processTimes() } std::vector::iterator TimeBlock::beginChildren() - { +{ return getTreeNode().mChildren.begin(); - } +} std::vector::iterator TimeBlock::endChildren() - { +{ return getTreeNode().mChildren.end(); } @@ -373,7 +372,7 @@ void TimeBlock::logStats() //static void TimeBlock::dumpCurTimes() - { +{ LLTrace::PeriodicRecording& frame_recording = LLTrace::get_frame_recording(); LLTrace::Recording& last_frame_recording = frame_recording.getLastRecording(); @@ -462,7 +461,7 @@ void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other ) mParent = other->mParent; } else -{ + { mStartTotalTimeCounter = mTotalTimeCounter; } } -- cgit v1.2.3 From e40065f82c797eab41006a448c838f4f1089a2e8 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Fri, 19 Jul 2013 15:03:05 -0700 Subject: BUILDFIX: #include and dependency cleanup --- indra/llcommon/llfasttimer.cpp | 22 +++++++++++----------- 1 file changed, 11 insertions(+), 11 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 79aa0c8722..6f046c18ff 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -111,9 +111,9 @@ static timer_tree_dfs_iterator_t end_timer_tree() struct SortTimerByName { bool operator()(const TimeBlock* i1, const TimeBlock* i2) - { + { return i1->getName() < i2->getName(); - } + } }; TimeBlock& TimeBlock::getRootTimeBlock() @@ -227,17 +227,17 @@ void TimeBlock::incrementalUpdateTimerTree() if (accumulator->mMoveUpTree) { - // since ancestors have already been visited, re-parenting 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()); - accumulator->mParent = timerp->getParent(); - accumulator->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 + // as ancestors may call this timer only on certain paths, so we want to resolve + // child-most block locations before their parents it.skipAncestors(); } } @@ -357,7 +357,7 @@ void TimeBlock::logStats() // doesn't work correctly on the first frame total_time += frame_recording.getLastRecording().getSum(timer); } - } +} sd["Total"]["Time"] = (LLSD::Real) total_time.value(); sd["Total"]["Calls"] = (LLSD::Integer) 1; @@ -366,7 +366,7 @@ void TimeBlock::logStats() LLMutexLock lock(sLogLock); sLogQueue.push(sd); } - } +} } @@ -413,7 +413,7 @@ void TimeBlock::writeLog(std::ostream& os) LLSDSerialize::toXML(sd, os); LLMutexLock lock(sLogLock); sLogQueue.pop(); - } + } } ////////////////////////////////////////////////////////////////////////////////////////////////////////////////// @@ -470,7 +470,7 @@ LLUnit BlockTimer::getElapsedTime() { U64 total_time = TimeBlock::getCPUClockCount64() - mStartTime; - return (F64)total_time / (F64)TimeBlock::countsPerSecond(); + return LLUnits::Seconds::fromValue((F64)total_time / (F64)TimeBlock::countsPerSecond()); } -- cgit v1.2.3 From bd5808765f7a74226d312afbb863c471528b8d1a Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Wed, 31 Jul 2013 19:32:50 -0700 Subject: cleanup - renamed valueAs to valueInUnits and made it a symmetrical getter/setter --- indra/llcommon/llfasttimer.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 6f046c18ff..f4c87ab6f6 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -397,7 +397,7 @@ void TimeBlock::dumpCurTimes() } out_str << timerp->getName() << " " - << std::setprecision(3) << total_time.valueAs() << " ms, " + << std::setprecision(3) << total_time.valueInUnits() << " ms, " << num_calls << " calls"; llinfos << out_str.str() << llendl; -- cgit v1.2.3 From 8d3daa141e9ea14f533559843d77ab5c0f715421 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Fri, 9 Aug 2013 16:14:19 -0700 Subject: SH-4374 FIX Interesting: Statistics Object cache hit rate is always 100% moved object cache sampling code so that it actually gets executed default values for stats are NaN instead of 0 in many cases --- indra/llcommon/llfasttimer.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index f4c87ab6f6..3b17b6022c 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -431,11 +431,11 @@ TimeBlockAccumulator::TimeBlockAccumulator() mParent(NULL) {} -void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other, bool append ) +void TimeBlockAccumulator::addSamples( const TimeBlockAccumulator& other, EBufferAppendType append_type ) { // we can't merge two unrelated time block samples, as that will screw with the nested timings // due to the call hierarchy of each thread - llassert(append); + llassert(append_type == SEQUENTIAL); mTotalTimeCounter += other.mTotalTimeCounter - other.mStartTotalTimeCounter; mSelfTimeCounter += other.mSelfTimeCounter; mCalls += other.mCalls; -- cgit v1.2.3 From e340009fc59d59e59b2e8d903a884acb76b178eb Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Fri, 9 Aug 2013 17:11:19 -0700 Subject: second phase summer cleaning replace llinfos, lldebugs, etc with new LL_INFOS(), LL_DEBUGS(), etc. --- indra/llcommon/llfasttimer.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 3b17b6022c..8f86a1dfbc 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -400,7 +400,7 @@ void TimeBlock::dumpCurTimes() << std::setprecision(3) << total_time.valueInUnits() << " ms, " << num_calls << " calls"; - llinfos << out_str.str() << llendl; + LL_INFOS() << out_str.str() << LL_ENDL; } } -- cgit v1.2.3 From 26581404e426b00cd0a07c38b5cb858d5d5faa28 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Wed, 14 Aug 2013 11:51:49 -0700 Subject: BUILDFIX: added header for numeric_limits support on gcc added convenience types for units F32Seconds, etc. --- indra/llcommon/llfasttimer.cpp | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 8f86a1dfbc..a91e716f19 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -339,7 +339,7 @@ void TimeBlock::logStats() } call_count++; - LLUnit total_time(0); + LLUnits::F64Seconds total_time(0); LLSD sd; { @@ -382,11 +382,11 @@ void TimeBlock::dumpCurTimes() ++it) { TimeBlock* timerp = (*it); - LLUnit total_time = last_frame_recording.getSum(*timerp); + LLUnits::F64Seconds total_time = 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 < LLUnits::Milliseconds::fromValue(0.1f)) continue; + if (total_time < LLUnits::F32Milliseconds(0.1f)) continue; std::ostringstream out_str; TimeBlock* parent_timerp = timerp; @@ -466,11 +466,11 @@ void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other ) } } -LLUnit BlockTimer::getElapsedTime() +LLUnits::F64Seconds BlockTimer::getElapsedTime() { U64 total_time = TimeBlock::getCPUClockCount64() - mStartTime; - return LLUnits::Seconds::fromValue((F64)total_time / (F64)TimeBlock::countsPerSecond()); + return LLUnits::F64Seconds((F64)total_time / (F64)TimeBlock::countsPerSecond()); } -- cgit v1.2.3 From 9f7bfa1c3710856cd2b0a0a8a429d6c45b0fcd09 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Thu, 15 Aug 2013 00:02:23 -0700 Subject: moved unit types out of LLUnits namespace, since they are prefixed --- indra/llcommon/llfasttimer.cpp | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index a91e716f19..5f92c66f47 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -339,7 +339,7 @@ void TimeBlock::logStats() } call_count++; - LLUnits::F64Seconds total_time(0); + F64Seconds total_time(0); LLSD sd; { @@ -382,11 +382,11 @@ void TimeBlock::dumpCurTimes() ++it) { TimeBlock* timerp = (*it); - LLUnits::F64Seconds total_time = last_frame_recording.getSum(*timerp); + F64Seconds total_time = 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 < LLUnits::F32Milliseconds(0.1f)) continue; + if (total_time < F32Milliseconds(0.1f)) continue; std::ostringstream out_str; TimeBlock* parent_timerp = timerp; @@ -466,11 +466,11 @@ void TimeBlockAccumulator::reset( const TimeBlockAccumulator* other ) } } -LLUnits::F64Seconds BlockTimer::getElapsedTime() +F64Seconds BlockTimer::getElapsedTime() { U64 total_time = TimeBlock::getCPUClockCount64() - mStartTime; - return LLUnits::F64Seconds((F64)total_time / (F64)TimeBlock::countsPerSecond()); + return F64Seconds((F64)total_time / (F64)TimeBlock::countsPerSecond()); } -- cgit v1.2.3 From 3e31cb112daf0a759737ba4ec55a8772361483f2 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Mon, 19 Aug 2013 11:50:30 -0700 Subject: BUILDFIX: fixed some units errors --- indra/llcommon/llfasttimer.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 5f92c66f47..d99c4c990e 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -335,7 +335,7 @@ void TimeBlock::logStats() 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()) / (LLUnit(LLProcessorInfo().getCPUFrequency())) << LL_ENDL; + LL_DEBUGS("FastTimers") << "elapsed sec " << ((F64)getCPUClockCount64() / (F64HertzImplicit)LLProcessorInfo().getCPUFrequency()) << LL_ENDL; } call_count++; -- cgit v1.2.3 From 2c6bc5afa59a88136fd6de4ebf0cb99ea7cdef3f Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Wed, 21 Aug 2013 14:06:57 -0700 Subject: SH-4433 WIP Interesting: Statistics > Ping Sim is always 0 ms made getPrimaryAccumulator return a reference since it was an always non-null pointer changed unit conversion to perform lazy division in order to avoid truncation of timer values --- indra/llcommon/llfasttimer.cpp | 28 ++++++++++++++-------------- 1 file changed, 14 insertions(+), 14 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index d99c4c990e..ae3234a87a 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -189,15 +189,15 @@ void TimeBlock::bootstrapTimerTree() // when this timer was called if (timer.getParent() == &TimeBlock::getRootTimeBlock()) { - TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator(); + TimeBlockAccumulator& accumulator = timer.getPrimaryAccumulator(); - if (accumulator->mLastCaller) + if (accumulator.mLastCaller) { - timer.setParent(accumulator->mLastCaller); - accumulator->mParent = accumulator->mLastCaller; + 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; + accumulator.mMoveUpTree = false; } } } @@ -223,17 +223,17 @@ void TimeBlock::incrementalUpdateTimerTree() // skip root timer if (timerp != &TimeBlock::getRootTimeBlock()) { - TimeBlockAccumulator* accumulator = timerp->getPrimaryAccumulator(); + TimeBlockAccumulator& accumulator = timerp->getPrimaryAccumulator(); - if (accumulator->mMoveUpTree) + if (accumulator.mMoveUpTree) { // 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()); - accumulator->mParent = timerp->getParent(); - accumulator->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 @@ -253,7 +253,7 @@ void TimeBlock::updateTimes() U64 cur_time = getCPUClockCount64(); BlockTimer* cur_timer = stack_record->mActiveTimer; - TimeBlockAccumulator* accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); + TimeBlockAccumulator* accumulator = &stack_record->mTimeBlock->getPrimaryAccumulator(); while(cur_timer && cur_timer->mParentTimerData.mActiveTimer != cur_timer) // root defined by parent pointing to self @@ -269,7 +269,7 @@ void TimeBlock::updateTimes() cur_timer->mBlockStartTotalTimeCounter = accumulator->mTotalTimeCounter; stack_record = &cur_timer->mParentTimerData; - accumulator = stack_record->mTimeBlock->getPrimaryAccumulator(); + accumulator = &stack_record->mTimeBlock->getPrimaryAccumulator(); cur_timer = stack_record->mActiveTimer; stack_record->mChildTime += cumulative_time_delta; @@ -299,10 +299,10 @@ void TimeBlock::processTimes() ++it) { TimeBlock& timer = *it; - TimeBlockAccumulator* accumulator = timer.getPrimaryAccumulator(); + TimeBlockAccumulator& accumulator = timer.getPrimaryAccumulator(); - accumulator->mLastCaller = NULL; - accumulator->mMoveUpTree = false; + accumulator.mLastCaller = NULL; + accumulator.mMoveUpTree = false; } } -- cgit v1.2.3 From a7aed07a5b620977fb74e4070e432eef01d11d3c Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Tue, 27 Aug 2013 13:41:19 -0700 Subject: broke out llunit.h into llunittype.h and llunits.h for unit declarations changed unit declarations macros to make a lot more sense --- indra/llcommon/llfasttimer.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index ae3234a87a..2235eb1a08 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -32,7 +32,7 @@ #include "llsingleton.h" #include "lltreeiterators.h" #include "llsdserialize.h" -#include "llunit.h" +#include "llunits.h" #include "llsd.h" #include "lltracerecording.h" #include "lltracethreadrecorder.h" -- cgit v1.2.3 From cbe397ad13665c7bc993e10d8fe1e4a876253378 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Thu, 5 Sep 2013 14:04:13 -0700 Subject: changed fast timer over to using macro another attempt to move mem stat into base class --- indra/llcommon/llfasttimer.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) (limited to 'indra/llcommon/llfasttimer.cpp') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index 2235eb1a08..be240c754a 100755 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -276,13 +276,13 @@ void TimeBlock::updateTimes() } } -static LLFastTimer::DeclareTimer FTM_PROCESS_TIMES("Process FastTimer Times"); +static LLTrace::TimeBlock FTM_PROCESS_TIMES("Process FastTimer Times"); // not thread safe, so only call on main thread //static void TimeBlock::processTimes() { - LLFastTimer _(FTM_PROCESS_TIMES); + LL_RECORD_BLOCK_TIME(FTM_PROCESS_TIMES); get_clock_count(); // good place to calculate clock frequency // set up initial tree @@ -413,7 +413,7 @@ void TimeBlock::writeLog(std::ostream& os) LLSDSerialize::toXML(sd, os); LLMutexLock lock(sLogLock); sLogQueue.pop(); - } + } } ////////////////////////////////////////////////////////////////////////////////////////////////////////////////// -- cgit v1.2.3