From a98c7e150b3404cbbb7324bfe2a5f547f613346b Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Mon, 6 Aug 2012 16:08:04 -0700 Subject: llfasttimer cleanup removed unnecessary cache miss from fast timers renamed llfasttimer_class back to llfasttimer --- indra/llcommon/llfasttimer.h | 362 ++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 358 insertions(+), 4 deletions(-) (limited to 'indra/llcommon/llfasttimer.h') diff --git a/indra/llcommon/llfasttimer.h b/indra/llcommon/llfasttimer.h index 2b25f2fabb..e42e549df5 100644 --- a/indra/llcommon/llfasttimer.h +++ b/indra/llcommon/llfasttimer.h @@ -1,6 +1,6 @@ /** * @file llfasttimer.h - * @brief Inline implementations of fast timers. + * @brief Declaration of a fast timer. * * $LicenseInfo:firstyear=2004&license=viewerlgpl$ * Second Life Viewer Source Code @@ -27,9 +27,363 @@ #ifndef LL_FASTTIMER_H #define LL_FASTTIMER_H -// Implementation of getCPUClockCount32() and getCPUClockCount64 are now in llfastertimer_class.cpp. +#include "llinstancetracker.h" -// pull in the actual class definition -#include "llfasttimer_class.h" +#define FAST_TIMER_ON 1 +#define DEBUG_FAST_TIMER_THREADS 1 + +class LLMutex; + +#include +#include "llsd.h" + +#define LL_FASTTIMER_USE_RDTSC 1 + + +LL_COMMON_API void assert_main_thread(); + +class LL_COMMON_API LLFastTimer +{ +public: + class NamedTimer; + + struct LL_COMMON_API FrameState + { + FrameState(); + void setNamedTimer(NamedTimer* timerp) { mTimer = timerp; } + + U32 mSelfTimeCounter; + U32 mCalls; + FrameState* mParent; // info for caller timer + FrameState* mLastCaller; // used to bootstrap tree construction + NamedTimer* mTimer; + U16 mActiveCount; // number of timers with this ID active on stack + bool mMoveUpTree; // needs to be moved up the tree of timers at the end of frame + }; + + // stores a "named" timer instance to be reused via multiple LLFastTimer stack instances + class LL_COMMON_API NamedTimer + : public LLInstanceTracker + { + friend class DeclareTimer; + public: + ~NamedTimer(); + + enum { HISTORY_NUM = 300 }; + + const std::string& getName() const { return mName; } + NamedTimer* getParent() const { return mParent; } + void setParent(NamedTimer* parent); + S32 getDepth(); + std::string getToolTip(S32 history_index = -1); + + typedef std::vector::const_iterator child_const_iter; + child_const_iter beginChildren(); + child_const_iter endChildren(); + std::vector& getChildren(); + + void setCollapsed(bool collapsed) { mCollapsed = collapsed; } + bool getCollapsed() const { return mCollapsed; } + + U32 getCountAverage() const { return mCountAverage; } + U32 getCallAverage() const { return mCallAverage; } + + U32 getHistoricalCount(S32 history_index = 0) const; + U32 getHistoricalCalls(S32 history_index = 0) const; + + void setFrameState(FrameState* state) { mFrameState = state; state->setNamedTimer(this); } + FrameState& getFrameState() const; + + private: + friend class LLFastTimer; + friend class NamedTimerFactory; + + // + // methods + // + NamedTimer(const std::string& name); + // recursive call to gather total time from children + static void accumulateTimings(); + + // updates cumulative times and hierarchy, + // can be called multiple times in a frame, at any point + static void processTimes(); + + static void buildHierarchy(); + static void resetFrame(); + static void reset(); + + // + // members + // + FrameState* mFrameState; + + std::string mName; + + U32 mTotalTimeCounter; + + U32 mCountAverage; + U32 mCallAverage; + + U32* mCountHistory; + U32* mCallHistory; + + // tree structure + NamedTimer* mParent; // NamedTimer of caller(parent) + std::vector mChildren; + bool mCollapsed; // don't show children + bool mNeedsSorting; // sort children whenever child added + }; + + // used to statically declare a new named timer + class LL_COMMON_API DeclareTimer + : public LLInstanceTracker + { + friend class LLFastTimer; + public: + DeclareTimer(const std::string& name, bool open); + DeclareTimer(const std::string& name); + + NamedTimer& getNamedTimer() { return mTimer; } + + private: + FrameState mFrameState; + NamedTimer& mTimer; + }; + +public: + LLFastTimer(LLFastTimer::FrameState* state); + + LL_FORCE_INLINE LLFastTimer(LLFastTimer::DeclareTimer& timer) + : mFrameState(&timer.mFrameState) + { +#if FAST_TIMER_ON + LLFastTimer::FrameState* frame_state = mFrameState; + mStartTime = getCPUClockCount32(); + + frame_state->mActiveCount++; + frame_state->mCalls++; + // keep current parent as long as it is active when we are + frame_state->mMoveUpTree |= (frame_state->mParent->mActiveCount == 0); + + LLFastTimer::CurTimerData* cur_timer_data = &LLFastTimer::sCurTimerData; + mLastTimerData = *cur_timer_data; + cur_timer_data->mCurTimer = this; + cur_timer_data->mFrameState = frame_state; + cur_timer_data->mChildTime = 0; +#endif +#if DEBUG_FAST_TIMER_THREADS +#if !LL_RELEASE + assert_main_thread(); +#endif +#endif + } + + LL_FORCE_INLINE ~LLFastTimer() + { +#if FAST_TIMER_ON + LLFastTimer::FrameState* frame_state = mFrameState; + U32 total_time = getCPUClockCount32() - mStartTime; + + frame_state->mSelfTimeCounter += total_time - LLFastTimer::sCurTimerData.mChildTime; + frame_state->mActiveCount--; + + // store last caller to bootstrap tree creation + // do this in the destructor in case of recursion to get topmost caller + frame_state->mLastCaller = mLastTimerData.mFrameState; + + // we are only tracking self time, so subtract our total time delta from parents + mLastTimerData.mChildTime += total_time; + + LLFastTimer::sCurTimerData = mLastTimerData; +#endif + } + +public: + static LLMutex* sLogLock; + static std::queue sLogQueue; + static BOOL sLog; + static BOOL sMetricLog; + static std::string sLogName; + static bool sPauseHistory; + static bool sResetHistory; + + // call this once a frame to reset timers + static void nextFrame(); + + // dumps current cumulative frame stats to log + // call nextFrame() to reset timers + static void dumpCurTimes(); + + // call this to reset timer hierarchy, averages, etc. + static void reset(); + + static U64 countsPerSecond(); + static S32 getLastFrameIndex() { return sLastFrameIndex; } + static S32 getCurFrameIndex() { return sCurFrameIndex; } + + static void writeLog(std::ostream& os); + static const NamedTimer* getTimerByName(const std::string& name); + + struct CurTimerData + { + LLFastTimer* mCurTimer; + FrameState* mFrameState; + U32 mChildTime; + }; + static CurTimerData sCurTimerData; + +private: + + + ////////////////////////////////////////////////////////////////////////////// + // + // Important note: These implementations must be FAST! + // + + +#if LL_WINDOWS + // + // Windows implementation of CPU clock + // + + // + // NOTE: put back in when we aren't using platform sdk anymore + // + // because MS has different signatures for these functions in winnt.h + // need to rename them to avoid conflicts + //#define _interlockedbittestandset _renamed_interlockedbittestandset + //#define _interlockedbittestandreset _renamed_interlockedbittestandreset + //#include + //#undef _interlockedbittestandset + //#undef _interlockedbittestandreset + + //inline U32 LLFastTimer::getCPUClockCount32() + //{ + // U64 time_stamp = __rdtsc(); + // return (U32)(time_stamp >> 8); + //} + // + //// return full timer value, *not* shifted by 8 bits + //inline U64 LLFastTimer::getCPUClockCount64() + //{ + // return __rdtsc(); + //} + + // shift off lower 8 bits for lower resolution but longer term timing + // on 1Ghz machine, a 32-bit word will hold ~1000 seconds of timing +#if LL_FASTTIMER_USE_RDTSC + static U32 getCPUClockCount32() + { + U32 ret_val; + __asm + { + _emit 0x0f + _emit 0x31 + shr eax,8 + shl edx,24 + or eax, edx + mov dword ptr [ret_val], eax + } + return ret_val; + } + + // return full timer value, *not* shifted by 8 bits + static U64 getCPUClockCount64() + { + U64 ret_val; + __asm + { + _emit 0x0f + _emit 0x31 + mov eax,eax + mov edx,edx + mov dword ptr [ret_val+4], edx + mov dword ptr [ret_val], eax + } + return ret_val; + } + +#else + //LL_COMMON_API U64 get_clock_count(); // in lltimer.cpp + // These use QueryPerformanceCounter, which is arguably fine and also works on AMD architectures. + static U32 getCPUClockCount32() + { + return (U32)(get_clock_count()>>8); + } + + static U64 getCPUClockCount64() + { + return get_clock_count(); + } + +#endif + +#endif + + +#if (LL_LINUX || LL_SOLARIS) && !(defined(__i386__) || defined(__amd64__)) + // + // Linux and Solaris implementation of CPU clock - non-x86. + // This is accurate but SLOW! Only use out of desperation. + // + // Try to use the MONOTONIC clock if available, this is a constant time counter + // with nanosecond resolution (but not necessarily accuracy) and attempts are + // made to synchronize this value between cores at kernel start. It should not + // be affected by CPU frequency. If not available use the REALTIME clock, but + // this may be affected by NTP adjustments or other user activity affecting + // the system time. + static U64 getCPUClockCount64() + { + struct timespec tp; + +#ifdef CLOCK_MONOTONIC // MONOTONIC supported at build-time? + if (-1 == clock_gettime(CLOCK_MONOTONIC,&tp)) // if MONOTONIC isn't supported at runtime then ouch, try REALTIME +#endif + clock_gettime(CLOCK_REALTIME,&tp); + + return (tp.tv_sec*sClockResolution)+tp.tv_nsec; + } + + static U32 getCPUClockCount32() + { + return (U32)(getCPUClockCount64() >> 8); + } + +#endif // (LL_LINUX || LL_SOLARIS) && !(defined(__i386__) || defined(__amd64__)) + + +#if (LL_LINUX || LL_SOLARIS || LL_DARWIN) && (defined(__i386__) || defined(__amd64__)) + // + // Mac+Linux+Solaris FAST x86 implementation of CPU clock + static U32 getCPUClockCount32() + { + U64 x; + __asm__ volatile (".byte 0x0f, 0x31": "=A"(x)); + return (U32)(x >> 8); + } + + static U64 getCPUClockCount64() + { + U64 x; + __asm__ volatile (".byte 0x0f, 0x31": "=A"(x)); + return x; + } + +#endif + + static U64 sClockResolution; + + static S32 sCurFrameIndex; + static S32 sLastFrameIndex; + static U64 sLastFrameTime; + + U32 mStartTime; + LLFastTimer::FrameState* mFrameState; + LLFastTimer::CurTimerData mLastTimerData; + +}; + +typedef class LLFastTimer LLFastTimer; #endif // LL_LLFASTTIMER_H -- cgit v1.3 From 64201b21b3d02f98969981723ef5426cdbfc16be Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Thu, 30 Aug 2012 16:46:37 -0700 Subject: MAINT-1486 FIX Crash on login (Unhandled exception) allow duplicate named fast timers again, refactored timer code --- indra/llcommon/llfasttimer.cpp | 34 +++++++++++++++++++--------------- indra/llcommon/llfasttimer.h | 10 +++++----- indra/newview/llfasttimerview.cpp | 4 ++-- 3 files changed, 26 insertions(+), 22 deletions(-) (limited to 'indra/llcommon/llfasttimer.h') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index ff6806082c..b233b18f45 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -113,10 +113,9 @@ public: /*virtual */ void initSingleton() { mTimerRoot = new LLFastTimer::NamedTimer("root"); - mRootFrameState.setNamedTimer(mTimerRoot); - mTimerRoot->setFrameState(&mRootFrameState); + mRootFrameState = &mTimerRoot->getFrameState(); mTimerRoot->mParent = mTimerRoot; - mRootFrameState.mParent = &mRootFrameState; + mRootFrameState->mParent = mRootFrameState; } ~NamedTimerFactory() @@ -126,17 +125,15 @@ public: delete mTimerRoot; } - LLFastTimer::NamedTimer& createNamedTimer(const std::string& name, LLFastTimer::FrameState* state) + LLFastTimer::NamedTimer& createNamedTimer(const std::string& name) { timer_map_t::iterator found_it = mTimers.find(name); if (found_it != mTimers.end()) { - llerrs << "Duplicate timer declaration for: " << name << llendl; return *found_it->second; } LLFastTimer::NamedTimer* timer = new LLFastTimer::NamedTimer(name); - timer->setFrameState(state); timer->setParent(mTimerRoot); mTimers.insert(std::make_pair(name, timer)); @@ -163,19 +160,21 @@ public: private: timer_map_t mTimers; - LLFastTimer::NamedTimer* mTimerRoot; - LLFastTimer::FrameState mRootFrameState; + LLFastTimer::NamedTimer* mTimerRoot; + LLFastTimer::FrameState* mRootFrameState; }; LLFastTimer::DeclareTimer::DeclareTimer(const std::string& name, bool open ) -: mTimer(NamedTimerFactory::instance().createNamedTimer(name, &mFrameState)) +: mTimer(NamedTimerFactory::instance().createNamedTimer(name)) { + mFrameState = &mTimer.getFrameState(); mTimer.setCollapsed(!open); } LLFastTimer::DeclareTimer::DeclareTimer(const std::string& name) -: mTimer(NamedTimerFactory::instance().createNamedTimer(name, &mFrameState)) +: mTimer(NamedTimerFactory::instance().createNamedTimer(name)) { + mFrameState = &mTimer.getFrameState(); } //static @@ -225,13 +224,13 @@ LLFastTimer::NamedTimer::NamedTimer(const std::string& name) mTotalTimeCounter(0), mCountAverage(0), mCallAverage(0), - mNeedsSorting(false), - mFrameState(NULL) + mNeedsSorting(false) { mCountHistory = new U32[HISTORY_NUM]; memset(mCountHistory, 0, sizeof(U32) * HISTORY_NUM); mCallHistory = new U32[HISTORY_NUM]; memset(mCallHistory, 0, sizeof(U32) * HISTORY_NUM); + mFrameState.setNamedTimer(this); } LLFastTimer::NamedTimer::~NamedTimer() @@ -291,7 +290,7 @@ S32 LLFastTimer::NamedTimer::getDepth() { S32 depth = 0; NamedTimer* timerp = mParent; - while(timerp) + while(timerp && timerp->mParent != timerp) { depth++; timerp = timerp->mParent; @@ -546,9 +545,14 @@ U32 LLFastTimer::NamedTimer::getHistoricalCalls(S32 history_index ) const return mCallHistory[history_idx]; } -LLFastTimer::FrameState& LLFastTimer::NamedTimer::getFrameState() const +const LLFastTimer::FrameState& LLFastTimer::NamedTimer::getFrameState() const { - return *mFrameState; + return mFrameState; +} + +LLFastTimer::FrameState& LLFastTimer::NamedTimer::getFrameState() +{ + return mFrameState; } std::vector::const_iterator LLFastTimer::NamedTimer::beginChildren() diff --git a/indra/llcommon/llfasttimer.h b/indra/llcommon/llfasttimer.h index e42e549df5..07af0f1d4d 100644 --- a/indra/llcommon/llfasttimer.h +++ b/indra/llcommon/llfasttimer.h @@ -91,8 +91,8 @@ public: U32 getHistoricalCount(S32 history_index = 0) const; U32 getHistoricalCalls(S32 history_index = 0) const; - void setFrameState(FrameState* state) { mFrameState = state; state->setNamedTimer(this); } - FrameState& getFrameState() const; + const FrameState& getFrameState() const; + FrameState& getFrameState(); private: friend class LLFastTimer; @@ -116,7 +116,7 @@ public: // // members // - FrameState* mFrameState; + FrameState mFrameState; std::string mName; @@ -147,7 +147,7 @@ public: NamedTimer& getNamedTimer() { return mTimer; } private: - FrameState mFrameState; + FrameState* mFrameState; NamedTimer& mTimer; }; @@ -155,7 +155,7 @@ public: LLFastTimer(LLFastTimer::FrameState* state); LL_FORCE_INLINE LLFastTimer(LLFastTimer::DeclareTimer& timer) - : mFrameState(&timer.mFrameState) + : mFrameState(timer.mFrameState) { #if FAST_TIMER_ON LLFastTimer::FrameState* frame_state = mFrameState; diff --git a/indra/newview/llfasttimerview.cpp b/indra/newview/llfasttimerview.cpp index 59bf70f488..fd92f8ac18 100644 --- a/indra/newview/llfasttimerview.cpp +++ b/indra/newview/llfasttimerview.cpp @@ -511,7 +511,7 @@ void LLFastTimerView::draw() x += dx; BOOL is_child_of_hover_item = (idp == mHoverID); LLFastTimer::NamedTimer* next_parent = idp->getParent(); - while(!is_child_of_hover_item && next_parent) + while(!is_child_of_hover_item && next_parent && next_parent != next_parent->getParent()) { is_child_of_hover_item = (mHoverID == next_parent); next_parent = next_parent->getParent(); @@ -778,7 +778,7 @@ void LLFastTimerView::draw() BOOL is_child_of_hover_item = (idp == mHoverID); LLFastTimer::NamedTimer* next_parent = idp->getParent(); - while(!is_child_of_hover_item && next_parent) + while(!is_child_of_hover_item && next_parent && next_parent != next_parent->getParent()) { is_child_of_hover_item = (mHoverID == next_parent); next_parent = next_parent->getParent(); -- cgit v1.3 From afc2807302f2a94b5cbb0fe86f304984ac7e50b8 Mon Sep 17 00:00:00 2001 From: Richard Linden Date: Thu, 30 Aug 2012 18:35:29 -0700 Subject: MAINT-1486 FIX Crash on login (Unhandled exception) cleaner implementation of llfasttimers...don't bother to share similarly named timers just create multiple timers with same name...doesn't break anything --- indra/llcommon/llfasttimer.cpp | 10 ++-------- indra/llcommon/llfasttimer.h | 1 + indra/newview/llfasttimerview.cpp | 2 ++ 3 files changed, 5 insertions(+), 8 deletions(-) (limited to 'indra/llcommon/llfasttimer.h') diff --git a/indra/llcommon/llfasttimer.cpp b/indra/llcommon/llfasttimer.cpp index ff6806082c..d54e1a93ea 100644 --- a/indra/llcommon/llfasttimer.cpp +++ b/indra/llcommon/llfasttimer.cpp @@ -128,13 +128,6 @@ public: LLFastTimer::NamedTimer& createNamedTimer(const std::string& name, LLFastTimer::FrameState* state) { - timer_map_t::iterator found_it = mTimers.find(name); - if (found_it != mTimers.end()) - { - llerrs << "Duplicate timer declaration for: " << name << llendl; - return *found_it->second; - } - LLFastTimer::NamedTimer* timer = new LLFastTimer::NamedTimer(name); timer->setFrameState(state); timer->setParent(mTimerRoot); @@ -155,7 +148,7 @@ public: LLFastTimer::NamedTimer* getRootTimer() { return mTimerRoot; } - typedef std::map timer_map_t; + 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(); } @@ -294,6 +287,7 @@ S32 LLFastTimer::NamedTimer::getDepth() while(timerp) { depth++; + if (timerp->getParent() == timerp) break; timerp = timerp->mParent; } return depth; diff --git a/indra/llcommon/llfasttimer.h b/indra/llcommon/llfasttimer.h index e42e549df5..b3f7304664 100644 --- a/indra/llcommon/llfasttimer.h +++ b/indra/llcommon/llfasttimer.h @@ -145,6 +145,7 @@ public: DeclareTimer(const std::string& name); NamedTimer& getNamedTimer() { return mTimer; } + const NamedTimer& getNamedTimer() const { return mTimer; } private: FrameState mFrameState; diff --git a/indra/newview/llfasttimerview.cpp b/indra/newview/llfasttimerview.cpp index 59bf70f488..4dfb93f1bc 100644 --- a/indra/newview/llfasttimerview.cpp +++ b/indra/newview/llfasttimerview.cpp @@ -514,6 +514,7 @@ void LLFastTimerView::draw() while(!is_child_of_hover_item && next_parent) { is_child_of_hover_item = (mHoverID == next_parent); + if (next_parent->getParent() == next_parent) break; next_parent = next_parent->getParent(); } @@ -781,6 +782,7 @@ void LLFastTimerView::draw() while(!is_child_of_hover_item && next_parent) { is_child_of_hover_item = (mHoverID == next_parent); + if (next_parent->getParent() == next_parent) break; next_parent = next_parent->getParent(); } -- cgit v1.3