diff options
Diffstat (limited to 'indra')
| -rw-r--r-- | indra/llcommon/llfasttimer_class.cpp | 46 | ||||
| -rw-r--r-- | indra/llcommon/llfasttimer_class.h | 18 | ||||
| -rw-r--r-- | indra/llcommon/llstat.cpp | 713 | ||||
| -rw-r--r-- | indra/llcommon/llstat.h | 222 | ||||
| -rw-r--r-- | indra/llmessage/llcircuit.cpp | 2 | ||||
| -rw-r--r-- | indra/llmessage/llcircuit.h | 3 | ||||
| -rw-r--r-- | indra/llmessage/lliohttpserver.cpp | 13 | ||||
| -rw-r--r-- | indra/llmessage/llmessagetemplate.h | 2 | ||||
| -rw-r--r-- | indra/llmessage/llpumpio.cpp | 3 | ||||
| -rw-r--r-- | indra/newview/app_settings/logcontrol.xml | 18 | ||||
| -rw-r--r-- | indra/newview/llfasttimerview.cpp | 12 | ||||
| -rw-r--r-- | indra/newview/llfasttimerview.h | 1 | ||||
| -rwxr-xr-x | indra/newview/lltexturefetch.cpp | 9 | ||||
| -rw-r--r-- | indra/newview/llviewerobjectlist.cpp | 37 | ||||
| -rw-r--r-- | indra/newview/llviewerregion.cpp | 7 | ||||
| -rw-r--r-- | indra/newview/llviewerstats.cpp | 89 | ||||
| -rw-r--r-- | indra/newview/llviewerstats.h | 3 | ||||
| -rw-r--r-- | indra/newview/llviewerstatsrecorder.cpp | 179 | ||||
| -rw-r--r-- | indra/newview/llviewerstatsrecorder.h | 67 | 
19 files changed, 230 insertions, 1214 deletions
| diff --git a/indra/llcommon/llfasttimer_class.cpp b/indra/llcommon/llfasttimer_class.cpp index 463f558c2c..449074dbfe 100644 --- a/indra/llcommon/llfasttimer_class.cpp +++ b/indra/llcommon/llfasttimer_class.cpp @@ -73,9 +73,6 @@ U64 LLFastTimer::sClockResolution = 1000000; // Microsecond resolution  #endif  std::vector<LLFastTimer::FrameState>* LLFastTimer::sTimerInfos = NULL; -U64				LLFastTimer::sTimerCycles = 0; -U32				LLFastTimer::sTimerCalls = 0; -  // FIXME: move these declarations to the relevant modules @@ -425,8 +422,8 @@ void LLFastTimer::NamedTimer::buildHierarchy()  		{  			// since ancestors have already been visited, reparenting won't affect tree traversal  			//step up tree, bringing our descendants with us -			//llinfos << "Moving " << timerp->getName() << " from child of " << timerp->getParent()->getName() << -			//	" to child of " << timerp->getParent()->getParent()->getName() << llendl; +			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; @@ -507,12 +504,12 @@ void LLFastTimer::NamedTimer::resetFrame()  		static S32 call_count = 0;  		if (call_count % 100 == 0)  		{ -			llinfos << "countsPerSecond (32 bit): " << countsPerSecond() << llendl; -			llinfos << "get_clock_count (64 bit): " << get_clock_count() << llendl; -			llinfos << "LLProcessorInfo().getCPUFrequency() " << LLProcessorInfo().getCPUFrequency() << llendl; -			llinfos << "getCPUClockCount32() " << getCPUClockCount32() << llendl; -			llinfos << "getCPUClockCount64() " << getCPUClockCount64() << llendl; -			llinfos << "elapsed sec " << ((F64)getCPUClockCount64())/((F64)LLProcessorInfo().getCPUFrequency()*1000000.0) << llendl; +			LL_DEBUGS("FastTimers") << "countsPerSecond (32 bit): " << countsPerSecond() << LL_ENDL; +			LL_DEBUGS("FastTimers") << "get_clock_count (64 bit): " << get_clock_count() << llendl; +			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;  		}  		call_count++; @@ -566,26 +563,21 @@ void LLFastTimer::NamedTimer::resetFrame()  	DeclareTimer::updateCachedPointers();  	// reset for next frame +	for (instance_iter it = beginInstances(); it != endInstances(); ++it)  	{ -		for (instance_iter it = beginInstances(); it != endInstances(); ++it) -		{ -			NamedTimer& timer = *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(); -			} +		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();  		}  	} - -	//sTimerCycles = 0; -	//sTimerCalls = 0;  }  //static diff --git a/indra/llcommon/llfasttimer_class.h b/indra/llcommon/llfasttimer_class.h index f481e968a6..8a12aa1372 100644 --- a/indra/llcommon/llfasttimer_class.h +++ b/indra/llcommon/llfasttimer_class.h @@ -30,7 +30,6 @@  #include "llinstancetracker.h"  #define FAST_TIMER_ON 1 -#define TIME_FAST_TIMERS 0  #define DEBUG_FAST_TIMER_THREADS 1  class LLMutex; @@ -157,9 +156,6 @@ public:  	LL_FORCE_INLINE LLFastTimer(LLFastTimer::DeclareTimer& timer)  	:	mFrameState(timer.mFrameState)  	{ -#if TIME_FAST_TIMERS -		U64 timer_start = getCPUClockCount64(); -#endif  #if FAST_TIMER_ON  		LLFastTimer::FrameState* frame_state = mFrameState;  		mStartTime = getCPUClockCount32(); @@ -175,10 +171,6 @@ public:  		cur_timer_data->mFrameState = frame_state;  		cur_timer_data->mChildTime = 0;  #endif -#if TIME_FAST_TIMERS -		U64 timer_end = getCPUClockCount64(); -		sTimerCycles += timer_end - timer_start; -#endif  #if DEBUG_FAST_TIMER_THREADS  #if !LL_RELEASE  		assert_main_thread(); @@ -188,9 +180,6 @@ public:  	LL_FORCE_INLINE ~LLFastTimer()  	{ -#if TIME_FAST_TIMERS -		U64 timer_start = getCPUClockCount64(); -#endif  #if FAST_TIMER_ON  		LLFastTimer::FrameState* frame_state = mFrameState;  		U32 total_time = getCPUClockCount32() - mStartTime; @@ -207,11 +196,6 @@ public:  		LLFastTimer::sCurTimerData = mLastTimerData;  #endif -#if TIME_FAST_TIMERS -		U64 timer_end = getCPUClockCount64(); -		sTimerCycles += timer_end - timer_start; -		sTimerCalls++; -#endif  	}  public: @@ -222,8 +206,6 @@ public:  	static std::string		sLogName;  	static bool 			sPauseHistory;  	static bool 			sResetHistory; -	static U64				sTimerCycles; -	static U32				sTimerCalls;  	typedef std::vector<FrameState> info_list_t;  	static info_list_t& getFrameStateList(); diff --git a/indra/llcommon/llstat.cpp b/indra/llcommon/llstat.cpp index 057257057f..5cf5ae3c12 100644 --- a/indra/llcommon/llstat.cpp +++ b/indra/llcommon/llstat.cpp @@ -37,715 +37,8 @@  // statics -S32	            LLPerfBlock::sStatsFlags = LLPerfBlock::LLSTATS_NO_OPTIONAL_STATS;       // Control what is being recorded -LLPerfBlock::stat_map_t    LLPerfBlock::sStatMap;    // Map full path string to LLStatTime objects, tracks all active objects -std::string        LLPerfBlock::sCurrentStatPath = "";    // Something like "/total_time/physics/physics step"  LLStat::stat_map_t LLStat::sStatList; -  //------------------------------------------------------------------------ -// Live config file to trigger stats logging -static const char    STATS_CONFIG_FILE_NAME[]            = "/dev/shm/simperf/simperf_proc_config.llsd"; -static const F32    STATS_CONFIG_REFRESH_RATE            = 5.0;        // seconds - -class LLStatsConfigFile : public LLLiveFile -{ -public: -    LLStatsConfigFile() -        : LLLiveFile(filename(), STATS_CONFIG_REFRESH_RATE), -        mChanged(false), mStatsp(NULL) { } - -    static std::string filename(); -     -protected: -    /* virtual */ bool loadFile(); - -public: -    void init(LLPerfStats* statsp); -    static LLStatsConfigFile& instance(); -        // return the singleton stats config file - -    bool mChanged; - -protected: -    LLPerfStats*    mStatsp; -}; - -std::string LLStatsConfigFile::filename() -{ -    return STATS_CONFIG_FILE_NAME; -} - -void LLStatsConfigFile::init(LLPerfStats* statsp) -{ -    mStatsp = statsp; -} - -LLStatsConfigFile& LLStatsConfigFile::instance() -{ -    static LLStatsConfigFile the_file; -    return the_file; -} - - -/* virtual */ -// Load and parse the stats configuration file -bool LLStatsConfigFile::loadFile() -{ -    if (!mStatsp) -    { -        llwarns << "Tries to load performance configure file without initializing LPerfStats" << llendl; -        return false; -    } -    mChanged = true; -     -    LLSD stats_config; -    { -        llifstream file(filename().c_str()); -        if (file.is_open()) -        { -            LLSDSerialize::fromXML(stats_config, file); -            if (stats_config.isUndefined()) -            { -                llinfos << "Performance statistics configuration file ill-formed, not recording statistics" << llendl; -                mStatsp->setReportPerformanceDuration( 0.f ); -                return false; -            } -        } -        else  -        {    // File went away, turn off stats if it was on -            if ( mStatsp->frameStatsIsRunning() ) -            { -                llinfos << "Performance statistics configuration file deleted, not recording statistics" << llendl; -                mStatsp->setReportPerformanceDuration( 0.f ); -            } -            return true; -        } -    } - -    F32 duration = 0.f; -    F32 interval = 0.f; -	S32 flags = LLPerfBlock::LLSTATS_BASIC_STATS; - -    const char * w = "duration"; -    if (stats_config.has(w)) -    { -        duration = (F32)stats_config[w].asReal(); -    }  -    w = "interval"; -    if (stats_config.has(w)) -    { -        interval = (F32)stats_config[w].asReal(); -    }  -    w = "flags"; -    if (stats_config.has(w)) -    { -		flags = (S32)stats_config[w].asInteger(); -		if (flags == LLPerfBlock::LLSTATS_NO_OPTIONAL_STATS && -			duration > 0) -		{   // No flags passed in, but have a duration, so reset to basic stats -			flags = LLPerfBlock::LLSTATS_BASIC_STATS; -		} -    }  - -    mStatsp->setReportPerformanceDuration( duration, flags ); -    mStatsp->setReportPerformanceInterval( interval ); - -    if ( duration > 0 ) -    { -        if ( interval == 0.f ) -        { -            llinfos << "Recording performance stats every frame for " << duration << " sec" << llendl; -        } -        else -        { -            llinfos << "Recording performance stats every " << interval << " seconds for " << duration << " seconds" << llendl; -        } -    } -    else -    { -        llinfos << "Performance stats recording turned off" << llendl; -    } -	return true; -} - - -//------------------------------------------------------------------------ - -LLPerfStats::LLPerfStats(const std::string& process_name, S32 process_pid) :  -    mFrameStatsFileFailure(FALSE), -    mSkipFirstFrameStats(FALSE), -    mProcessName(process_name), -    mProcessPID(process_pid), -    mReportPerformanceStatInterval(1.f), -    mReportPerformanceStatEnd(0.0)  -{ } - -LLPerfStats::~LLPerfStats() -{ -    LLPerfBlock::clearDynamicStats(); -    mFrameStatsFile.close(); -} - -void LLPerfStats::init() -{ -    // Initialize the stats config file instance. -    (void) LLStatsConfigFile::instance().init(this); -    (void) LLStatsConfigFile::instance().checkAndReload(); -} - -// Open file for statistics -void    LLPerfStats::openPerfStatsFile() -{ -    if ( !mFrameStatsFile -        && !mFrameStatsFileFailure ) -    { -        std::string stats_file = llformat("/dev/shm/simperf/%s_proc.%d.llsd", mProcessName.c_str(), mProcessPID); -        mFrameStatsFile.close(); -        mFrameStatsFile.clear(); -        mFrameStatsFile.open(stats_file, llofstream::out); -        if ( mFrameStatsFile.fail() ) -        { -            llinfos << "Error opening statistics log file " << stats_file << llendl; -            mFrameStatsFileFailure = TRUE; -        } -        else -        { -            LLSD process_info = LLSD::emptyMap(); -            process_info["name"] = mProcessName; -            process_info["pid"] = (LLSD::Integer) mProcessPID; -            process_info["stat_rate"] = (LLSD::Integer) mReportPerformanceStatInterval; -            // Add process-specific info. -            addProcessHeaderInfo(process_info); - -            mFrameStatsFile << LLSDNotationStreamer(process_info) << std::endl;  -        } -    } -} - -// Dump out performance metrics over some time interval -void LLPerfStats::dumpIntervalPerformanceStats() -{ -    // Ensure output file is OK -    openPerfStatsFile(); - -    if ( mFrameStatsFile ) -    { -        LLSD stats = LLSD::emptyMap(); - -        LLStatAccum::TimeScale scale; -        if ( getReportPerformanceInterval() == 0.f ) -        { -            scale = LLStatAccum::SCALE_PER_FRAME; -        } -        else if ( getReportPerformanceInterval() < 0.5f ) -        { -            scale = LLStatAccum::SCALE_100MS; -        } -        else -        { -            scale = LLStatAccum::SCALE_SECOND; -        } - -        // Write LLSD into log -        stats["utc_time"] = (LLSD::String) LLError::utcTime(); -        stats["timestamp"] = U64_to_str((totalTime() / 1000) + (gUTCOffset * 1000));    // milliseconds since epoch -        stats["frame_number"] = (LLSD::Integer) LLFrameTimer::getFrameCount(); - -        // Add process-specific frame info. -        addProcessFrameInfo(stats, scale); -        LLPerfBlock::addStatsToLLSDandReset( stats, scale ); - -        mFrameStatsFile << LLSDNotationStreamer(stats) << std::endl;  -    } -} - -// Set length of performance stat recording.   -// If turning stats on, caller must provide flags -void    LLPerfStats::setReportPerformanceDuration( F32 seconds, S32 flags /* = LLSTATS_NO_OPTIONAL_STATS */ ) -{  -	if ( seconds <= 0.f ) -	{ -		mReportPerformanceStatEnd = 0.0; -		LLPerfBlock::setStatsFlags(LLPerfBlock::LLSTATS_NO_OPTIONAL_STATS);		// Make sure all recording is off -		mFrameStatsFile.close(); -		LLPerfBlock::clearDynamicStats(); -	} -	else -	{ -		mReportPerformanceStatEnd = LLFrameTimer::getElapsedSeconds() + ((F64) seconds); -		// Clear failure flag to try and create the log file once -		mFrameStatsFileFailure = FALSE; -		mSkipFirstFrameStats = TRUE;		// Skip the first report (at the end of this frame) -		LLPerfBlock::setStatsFlags(flags); -	} -} - -void LLPerfStats::updatePerFrameStats() -{ -    (void) LLStatsConfigFile::instance().checkAndReload(); -	static LLFrameTimer performance_stats_timer; -	if ( frameStatsIsRunning() ) -	{ -		if ( mReportPerformanceStatInterval == 0 ) -		{	// Record info every frame -			if ( mSkipFirstFrameStats ) -			{	// Skip the first time - was started this frame -				mSkipFirstFrameStats = FALSE; -			} -			else -			{ -				dumpIntervalPerformanceStats(); -			} -		} -		else -		{ -			performance_stats_timer.setTimerExpirySec( getReportPerformanceInterval() ); -			if (performance_stats_timer.checkExpirationAndReset( mReportPerformanceStatInterval )) -			{ -				dumpIntervalPerformanceStats(); -			} -		} -		 -		if ( LLFrameTimer::getElapsedSeconds() > mReportPerformanceStatEnd ) -		{	// Reached end of time, clear it to stop reporting -			setReportPerformanceDuration(0.f);			// Don't set mReportPerformanceStatEnd directly	 -            llinfos << "Recording performance stats completed" << llendl; -		} -	} -} - - -//------------------------------------------------------------------------ - -U64 LLStatAccum::sScaleTimes[NUM_SCALES] = -{ -	USEC_PER_SEC / 10,				// 100 millisec -	USEC_PER_SEC * 1,				// seconds -	USEC_PER_SEC * 60,				// minutes -#if ENABLE_LONG_TIME_STATS -	// enable these when more time scales are desired -	USEC_PER_SEC * 60*60,			// hours -	USEC_PER_SEC * 24*60*60,		// days -	USEC_PER_SEC * 7*24*60*60,		// weeks -#endif -}; - - - -LLStatAccum::LLStatAccum(bool useFrameTimer) -	: mUseFrameTimer(useFrameTimer), -	  mRunning(FALSE), -	  mLastTime(0), -	  mLastSampleValue(0.0), -	  mLastSampleValid(FALSE) -{ -} - -LLStatAccum::~LLStatAccum() -{ -} - - - -void LLStatAccum::reset(U64 when) -{ -	mRunning = TRUE; -	mLastTime = when; - -	for (int i = 0; i < NUM_SCALES; ++i) -	{ -		mBuckets[i].accum = 0.0; -		mBuckets[i].endTime = when + sScaleTimes[i]; -		mBuckets[i].lastValid = false; -	} -} - -void LLStatAccum::sum(F64 value) -{ -	sum(value, getCurrentUsecs()); -} - -void LLStatAccum::sum(F64 value, U64 when) -{ -	if (!mRunning) -	{ -		reset(when); -		return; -	} -	if (when < mLastTime) -	{ -		// This happens a LOT on some dual core systems. -		lldebugs << "LLStatAccum::sum clock has gone backwards from " -			<< mLastTime << " to " << when << ", resetting" << llendl; - -		reset(when); -		return; -	} - -	// how long is this value for -	U64 timeSpan = when - mLastTime; - -	for (int i = 0; i < NUM_SCALES; ++i) -	{ -		Bucket& bucket = mBuckets[i]; - -		if (when < bucket.endTime) -		{ -			bucket.accum += value; -		} -		else -		{ -			U64 timeScale = sScaleTimes[i]; - -			U64 timeLeft = when - bucket.endTime; -				// how much time is left after filling this bucket -			 -			if (timeLeft < timeScale) -			{ -				F64 valueLeft = value * timeLeft / timeSpan; - -				bucket.lastValid = true; -				bucket.lastAccum = bucket.accum + (value - valueLeft); -				bucket.accum = valueLeft; -				bucket.endTime += timeScale; -			} -			else -			{ -				U64 timeTail = timeLeft % timeScale; - -				bucket.lastValid = true; -				bucket.lastAccum = value * timeScale / timeSpan; -				bucket.accum = value * timeTail / timeSpan; -				bucket.endTime += (timeLeft - timeTail) + timeScale; -			} -		} -	} - -	mLastTime = when; -} - - -F32 LLStatAccum::meanValue(TimeScale scale) const -{ -	if (!mRunning) -	{ -		return 0.0; -	} -	if ( scale == SCALE_PER_FRAME ) -	{	// Per-frame not supported here -		scale = SCALE_100MS; -	} - -	if (scale < 0 || scale >= NUM_SCALES) -	{ -		llwarns << "llStatAccum::meanValue called for unsupported scale: " -			<< scale << llendl; -		return 0.0; -	} - -	const Bucket& bucket = mBuckets[scale]; - -	F64 value = bucket.accum; -	U64 timeLeft = bucket.endTime - mLastTime; -	U64 scaleTime = sScaleTimes[scale]; - -	if (bucket.lastValid) -	{ -		value += bucket.lastAccum * timeLeft / scaleTime; -	} -	else if (timeLeft < scaleTime) -	{ -		value *= scaleTime / (scaleTime - timeLeft); -	} -	else -	{ -		value = 0.0; -	} - -	return (F32)(value / scaleTime); -} - - -U64 LLStatAccum::getCurrentUsecs() const -{ -	if (mUseFrameTimer) -	{ -		return LLFrameTimer::getTotalTime(); -	} -	else -	{ -		return totalTime(); -	} -} - - -// ------------------------------------------------------------------------ - -LLStatRate::LLStatRate(bool use_frame_timer) -	: LLStatAccum(use_frame_timer) -{ -} - -void LLStatRate::count(U32 value) -{ -	sum((F64)value * sScaleTimes[SCALE_SECOND]); -} - - -void LLStatRate::mark() - {  -	// Effectively the same as count(1), but sets mLastSampleValue -	U64 when = getCurrentUsecs(); - -	if ( mRunning  -		 && (when > mLastTime) ) -	{	// Set mLastSampleValue to the time from the last mark() -		F64 duration = ((F64)(when - mLastTime)) / sScaleTimes[SCALE_SECOND]; -		if ( duration > 0.0 ) -		{ -			mLastSampleValue = 1.0 / duration; -		} -		else -		{ -			mLastSampleValue = 0.0; -		} -	} - -	sum( (F64) sScaleTimes[SCALE_SECOND], when); - } - - -// ------------------------------------------------------------------------ - - -LLStatMeasure::LLStatMeasure(bool use_frame_timer) -	: LLStatAccum(use_frame_timer) -{ -} - -void LLStatMeasure::sample(F64 value) -{ -	U64 when = getCurrentUsecs(); - -	if (mLastSampleValid) -	{ -		F64 avgValue = (value + mLastSampleValue) / 2.0; -		F64 interval = (F64)(when - mLastTime); - -		sum(avgValue * interval, when); -	} -	else -	{ -		reset(when); -	} - -	mLastSampleValid = TRUE; -	mLastSampleValue = value; -} - - -// ------------------------------------------------------------------------ - -LLStatTime::LLStatTime(const std::string & key) -	: LLStatAccum(false), -	  mFrameNumber(LLFrameTimer::getFrameCount()), -	  mTotalTimeInFrame(0), -	  mKey(key) -#if LL_DEBUG -	  , mRunning(FALSE) -#endif -{ -} - -void LLStatTime::start() -{ -	// Reset frame accumluation if the frame number has changed -	U32 frame_number = LLFrameTimer::getFrameCount(); -	if ( frame_number != mFrameNumber ) -	{ -		mFrameNumber = frame_number; -		mTotalTimeInFrame = 0; -	} - -	sum(0.0); - -#if LL_DEBUG -	// Shouldn't be running already -	llassert( !mRunning ); -	mRunning = TRUE; -#endif -} - -void LLStatTime::stop() -{ -	U64 end_time = getCurrentUsecs(); -	U64 duration = end_time - mLastTime; -	sum(F64(duration), end_time); -	//llinfos << "mTotalTimeInFrame incremented from  " << mTotalTimeInFrame << " to " << (mTotalTimeInFrame + duration) << llendl;  -	mTotalTimeInFrame += duration; - -#if LL_DEBUG -	mRunning = FALSE; -#endif -} - -/* virtual */ F32 LLStatTime::meanValue(TimeScale scale) const -{ -    if ( LLStatAccum::SCALE_PER_FRAME == scale ) -    { -        return (F32)mTotalTimeInFrame; -    } -    else -    { -        return LLStatAccum::meanValue(scale); -    } -} - - -// ------------------------------------------------------------------------ - - -// Use this constructor for pre-defined LLStatTime objects -LLPerfBlock::LLPerfBlock(LLStatTime* stat ) : mPredefinedStat(stat), mDynamicStat(NULL) -{ -    if (mPredefinedStat) -    { -        // If dynamic stats are turned on, this will create a separate entry in the stat map. -        initDynamicStat(mPredefinedStat->mKey); - -        // Start predefined stats.  These stats are not part of the stat map. -        mPredefinedStat->start(); -    } -} - -// Use this constructor for normal, optional LLPerfBlock time slices -LLPerfBlock::LLPerfBlock( const char* key ) : mPredefinedStat(NULL), mDynamicStat(NULL) -{ -    if ((sStatsFlags & LLSTATS_BASIC_STATS) == 0) -	{	// These are off unless the base set is enabled -		return; -	} - -	initDynamicStat(key); -} - -	 -// Use this constructor for dynamically created LLPerfBlock time slices -// that are only enabled by specific control flags -LLPerfBlock::LLPerfBlock( const char* key1, const char* key2, S32 flags ) : mPredefinedStat(NULL), mDynamicStat(NULL) -{ -    if ((sStatsFlags & flags) == 0) -	{ -		return; -	} - -    if (NULL == key2 || strlen(key2) == 0) -    { -        initDynamicStat(key1); -    } -    else -    { -        std::ostringstream key; -        key << key1 << "_" << key2; -        initDynamicStat(key.str()); -    } -} - -// Set up the result data map if dynamic stats are enabled -void LLPerfBlock::initDynamicStat(const std::string& key) -{ -    // Early exit if dynamic stats aren't enabled. -    if (sStatsFlags == LLSTATS_NO_OPTIONAL_STATS)  -		return; - -    mLastPath = sCurrentStatPath;		// Save and restore current path -    sCurrentStatPath += "/" + key;		// Add key to current path - -    // See if the LLStatTime object already exists -    stat_map_t::iterator iter = sStatMap.find(sCurrentStatPath); -    if ( iter == sStatMap.end() ) -    { -        // StatEntry object doesn't exist, so create it -        mDynamicStat = new StatEntry( key ); -        sStatMap[ sCurrentStatPath ] = mDynamicStat;	// Set the entry for this path -    } -    else -    { -        // Found this path in the map, use the object there -        mDynamicStat = (*iter).second;		// Get StatEntry for the current path -    } - -    if (mDynamicStat) -    { -        mDynamicStat->mStat.start(); -        mDynamicStat->mCount++; -    } -    else -    { -        llwarns << "Initialized NULL dynamic stat at '" << sCurrentStatPath << "'" << llendl; -       sCurrentStatPath = mLastPath; -    } -} - - -// Destructor does the time accounting -LLPerfBlock::~LLPerfBlock() -{ -    if (mPredefinedStat) mPredefinedStat->stop(); -    if (mDynamicStat) -    { -        mDynamicStat->mStat.stop(); -        sCurrentStatPath = mLastPath;	// Restore the path in case sStatsEnabled changed during this block -    } -} - - -// Clear the map of any dynamic stats.  Static routine -void LLPerfBlock::clearDynamicStats() -{ -    std::for_each(sStatMap.begin(), sStatMap.end(), DeletePairedPointer()); -    sStatMap.clear(); -} - -// static - Extract the stat info into LLSD -void LLPerfBlock::addStatsToLLSDandReset( LLSD & stats, -										  LLStatAccum::TimeScale scale ) -{ -    // If we aren't in per-frame scale, we need to go from second to microsecond. -    U32 scale_adjustment = 1; -    if (LLStatAccum::SCALE_PER_FRAME != scale) -    { -        scale_adjustment = USEC_PER_SEC; -    } -	stat_map_t::iterator iter = sStatMap.begin(); -	for ( ; iter != sStatMap.end(); ++iter ) -	{	// Put the entry into LLSD "/full/path/to/stat/" = microsecond total time -		const std::string & stats_full_path = (*iter).first; - -		StatEntry * stat = (*iter).second; -		if (stat) -		{ -            if (stat->mCount > 0) -            { -                stats[stats_full_path] = LLSD::emptyMap(); -                stats[stats_full_path]["us"] = (LLSD::Integer) (scale_adjustment * stat->mStat.meanValue(scale)); -                if (stat->mCount > 1) -                { -                    stats[stats_full_path]["count"] = (LLSD::Integer) stat->mCount; -                } -                stat->mCount = 0; -            } -		} -		else -		{	// Shouldn't have a NULL pointer in the map. -            llwarns << "Unexpected NULL dynamic stat at '" << stats_full_path << "'" << llendl; -		} -	}	 -} - - -// ------------------------------------------------------------------------ -  LLTimer LLStat::sTimer;  LLFrameTimer LLStat::sFrameTimer; @@ -786,9 +79,9 @@ LLStat::LLStat(const U32 num_bins, const BOOL use_frame_timer)  }  LLStat::LLStat(std::string name, U32 num_bins, BOOL use_frame_timer) -	: mUseFrameTimer(use_frame_timer), -	  mNumBins(num_bins), -	  mName(name) +:	mUseFrameTimer(use_frame_timer), +	mNumBins(num_bins), +	mName(name)  {  	init();  } diff --git a/indra/llcommon/llstat.h b/indra/llcommon/llstat.h index b877432e86..7718d40ffb 100644 --- a/indra/llcommon/llstat.h +++ b/indra/llcommon/llstat.h @@ -36,228 +36,6 @@  class	LLSD; -// Set this if longer stats are needed -#define ENABLE_LONG_TIME_STATS	0 - -// -// Accumulates statistics for an arbitrary length of time. -// Does this by maintaining a chain of accumulators, each one -// accumulation the results of the parent.  Can scale to arbitrary -// amounts of time with very low memory cost. -// - -class LL_COMMON_API LLStatAccum -{ -protected: -	LLStatAccum(bool use_frame_timer); -	virtual ~LLStatAccum(); - -public: -	enum TimeScale { -		SCALE_100MS, -		SCALE_SECOND, -		SCALE_MINUTE, -#if ENABLE_LONG_TIME_STATS -		SCALE_HOUR, -		SCALE_DAY, -		SCALE_WEEK, -#endif -		NUM_SCALES,			// Use to size storage arrays -		SCALE_PER_FRAME		// For latest frame information - should be after NUM_SCALES since this doesn't go into the time buckets -	}; - -	static U64 sScaleTimes[NUM_SCALES]; - -	virtual F32 meanValue(TimeScale scale) const; -		// see the subclasses for the specific meaning of value - -	F32 meanValueOverLast100ms()  const { return meanValue(SCALE_100MS);  } -	F32 meanValueOverLastSecond() const	{ return meanValue(SCALE_SECOND); } -	F32 meanValueOverLastMinute() const	{ return meanValue(SCALE_MINUTE); } - -	void reset(U64 when); - -	void sum(F64 value); -	void sum(F64 value, U64 when); - -	U64 getCurrentUsecs() const; -		// Get current microseconds based on timer type - -	BOOL	mUseFrameTimer; -	BOOL	mRunning; - -	U64		mLastTime; -	 -	struct Bucket -	{ -		Bucket() : -			accum(0.0), -			endTime(0), -			lastValid(false), -			lastAccum(0.0) -		{} - -		F64	accum; -		U64	endTime; - -		bool	lastValid; -		F64	lastAccum; -	}; - -	Bucket	mBuckets[NUM_SCALES]; - -	BOOL 	mLastSampleValid; -	F64 	mLastSampleValue; -}; - -class LL_COMMON_API LLStatMeasure : public LLStatAccum -	// gathers statistics about things that are measured -	// ex.: tempature, time dilation -{ -public: -	LLStatMeasure(bool use_frame_timer = true); - -	void sample(F64); -	void sample(S32 v) { sample((F64)v); } -	void sample(U32 v) { sample((F64)v); } -	void sample(S64 v) { sample((F64)v); } -	void sample(U64 v) { sample((F64)v); } -}; - - -class LL_COMMON_API LLStatRate : public LLStatAccum -	// gathers statistics about things that can be counted over time -	// ex.: LSL instructions executed, messages sent, simulator frames completed -	// renders it in terms of rate of thing per second -{ -public: -	LLStatRate(bool use_frame_timer = true); - -	void count(U32); -		// used to note that n items have occured -	 -	void mark(); -		// used for counting the rate thorugh a point in the code -}; - - -class LL_COMMON_API LLStatTime : public LLStatAccum -	// gathers statistics about time spent in a block of code -	// measure average duration per second in the block -{ -public: -	LLStatTime( const std::string & key = "undefined" ); - -	U32		mFrameNumber;		// Current frame number -	U64		mTotalTimeInFrame;	// Total time (microseconds) accumulated during the last frame - -	void	setKey( const std::string & key )		{ mKey = key;	}; - -	virtual F32 meanValue(TimeScale scale) const; - -private: -	void start();				// Start and stop measuring time block -	void stop(); - -	std::string		mKey;		// Tag representing this time block - -#if LL_DEBUG -	BOOL			mRunning;	// TRUE if start() has been called -#endif - -	friend class LLPerfBlock; -}; - -// ---------------------------------------------------------------------------- - - -// Use this class on the stack to record statistics about an area of code -class LL_COMMON_API LLPerfBlock -{ -public: -    struct StatEntry -    { -            StatEntry(const std::string& key) : mStat(LLStatTime(key)), mCount(0) {} -            LLStatTime  mStat; -            U32         mCount; -    }; -    typedef std::map<std::string, StatEntry*>		stat_map_t; - -	// Use this constructor for pre-defined LLStatTime objects -	LLPerfBlock(LLStatTime* stat); - -	// Use this constructor for normal, optional LLPerfBlock time slices -	LLPerfBlock( const char* key ); - -	// Use this constructor for dynamically created LLPerfBlock time slices -	// that are only enabled by specific control flags -	LLPerfBlock( const char* key1, const char* key2, S32 flags = LLSTATS_BASIC_STATS ); - -	~LLPerfBlock(); - -	enum -	{	// Stats bitfield flags -		LLSTATS_NO_OPTIONAL_STATS	= 0x00,		// No optional stats gathering, just pre-defined LLStatTime objects -		LLSTATS_BASIC_STATS			= 0x01,		// Gather basic optional runtime stats -		LLSTATS_SCRIPT_FUNCTIONS	= 0x02,		// Include LSL function calls -	}; -	static void setStatsFlags( S32 flags )	{ sStatsFlags = flags;	}; -	static S32  getStatsFlags()				{ return sStatsFlags;	}; - -	static void clearDynamicStats();		// Reset maps to clear out dynamic objects -	static void addStatsToLLSDandReset( LLSD & stats,		// Get current information and clear time bin -										LLStatAccum::TimeScale scale ); - -private: -	// Initialize dynamically created LLStatTime objects -    void initDynamicStat(const std::string& key); - -	std::string				mLastPath;				// Save sCurrentStatPath when this is called -	LLStatTime * 			mPredefinedStat;		// LLStatTime object to get data -	StatEntry *				mDynamicStat;   		// StatEntryobject to get data - -	static S32				sStatsFlags;			// Control what is being recorded -    static stat_map_t		sStatMap;				// Map full path string to LLStatTime objects -	static std::string		sCurrentStatPath;		// Something like "frame/physics/physics step" -}; - -// ---------------------------------------------------------------------------- - -class LL_COMMON_API LLPerfStats -{ -public: -    LLPerfStats(const std::string& process_name = "unknown", S32 process_pid = 0); -    virtual ~LLPerfStats(); - -    virtual void init();    // Reset and start all stat timers -    virtual void updatePerFrameStats(); -    // Override these function to add process-specific information to the performance log header and per-frame logging. -    virtual void addProcessHeaderInfo(LLSD& info) { /* not implemented */ } -    virtual void addProcessFrameInfo(LLSD& info, LLStatAccum::TimeScale scale) { /* not implemented */ } - -    // High-resolution frame stats -    BOOL    frameStatsIsRunning()                                { return (mReportPerformanceStatEnd > 0.);        }; -    F32     getReportPerformanceInterval() const                { return mReportPerformanceStatInterval;        }; -    void    setReportPerformanceInterval( F32 interval )        { mReportPerformanceStatInterval = interval;    }; -    void    setReportPerformanceDuration( F32 seconds, S32 flags = LLPerfBlock::LLSTATS_NO_OPTIONAL_STATS ); -    void    setProcessName(const std::string& process_name) { mProcessName = process_name; } -    void    setProcessPID(S32 process_pid) { mProcessPID = process_pid; } - -protected: -    void    openPerfStatsFile();                    // Open file for high resolution metrics logging -    void    dumpIntervalPerformanceStats(); - -    llofstream      mFrameStatsFile;            // File for per-frame stats -    BOOL            mFrameStatsFileFailure;        // Flag to prevent repeat opening attempts -    BOOL            mSkipFirstFrameStats;        // Flag to skip one (partial) frame report -    std::string     mProcessName; -    S32             mProcessPID; - -private: -    F32 mReportPerformanceStatInterval;    // Seconds between performance stats -    F64 mReportPerformanceStatEnd;        // End time (seconds) for performance stats -}; -  // ----------------------------------------------------------------------------  class LL_COMMON_API LLStat  { diff --git a/indra/llmessage/llcircuit.cpp b/indra/llmessage/llcircuit.cpp index e0410906fb..0c2d4b823d 100644 --- a/indra/llmessage/llcircuit.cpp +++ b/indra/llmessage/llcircuit.cpp @@ -679,7 +679,6 @@ void LLCircuitData::checkPacketInID(TPACKETID id, BOOL receive_resent)  		setPacketInID((id + 1) % LL_MAX_OUT_PACKET_ID);          mLastPacketGap = 0; -        mOutOfOrderRate.count(0);  		return;  	} @@ -775,7 +774,6 @@ void LLCircuitData::checkPacketInID(TPACKETID id, BOOL receive_resent)  		}  	} -    mOutOfOrderRate.count(gap);      mLastPacketGap = gap;  } diff --git a/indra/llmessage/llcircuit.h b/indra/llmessage/llcircuit.h index d1c400c6a2..c46fd56acc 100644 --- a/indra/llmessage/llcircuit.h +++ b/indra/llmessage/llcircuit.h @@ -126,8 +126,6 @@ public:  	S32			getUnackedPacketCount() const	{ return mUnackedPacketCount; }  	S32			getUnackedPacketBytes() const	{ return mUnackedPacketBytes; }  	F64         getNextPingSendTime() const { return mNextPingSendTime; } -    F32         getOutOfOrderRate(LLStatAccum::TimeScale scale = LLStatAccum::SCALE_MINUTE)  -                    { return mOutOfOrderRate.meanValue(scale); }      U32         getLastPacketGap() const { return mLastPacketGap; }      LLHost      getHost() const { return mHost; }  	F64			getLastPacketInTime() const		{ return mLastPacketInTime;	} @@ -275,7 +273,6 @@ protected:  	LLTimer	mExistenceTimer;	    // initialized when circuit created, used to track bandwidth numbers  	S32		mCurrentResendCount;	// Number of resent packets since last spam -    LLStatRate  mOutOfOrderRate;    // Rate of out of order packets coming in.      U32     mLastPacketGap;         // Gap in sequence number of last packet.  	const F32 mHeartbeatInterval; diff --git a/indra/llmessage/lliohttpserver.cpp b/indra/llmessage/lliohttpserver.cpp index 987f386aa3..74eaf9f025 100644 --- a/indra/llmessage/lliohttpserver.cpp +++ b/indra/llmessage/lliohttpserver.cpp @@ -141,6 +141,11 @@ private:  };  static LLFastTimer::DeclareTimer FTM_PROCESS_HTTP_PIPE("HTTP Pipe"); +static LLFastTimer::DeclareTimer FTM_PROCESS_HTTP_GET("HTTP Get"); +static LLFastTimer::DeclareTimer FTM_PROCESS_HTTP_PUT("HTTP Put"); +static LLFastTimer::DeclareTimer FTM_PROCESS_HTTP_POST("HTTP Post"); +static LLFastTimer::DeclareTimer FTM_PROCESS_HTTP_DELETE("HTTP Delete"); +  LLIOPipe::EStatus LLHTTPPipe::process_impl(  	const LLChannelDescriptors& channels,      buffer_ptr_t& buffer, @@ -177,12 +182,12 @@ LLIOPipe::EStatus LLHTTPPipe::process_impl(  		std::string verb = context[CONTEXT_REQUEST][CONTEXT_VERB];  		if(verb == HTTP_VERB_GET)  		{ -            LLPerfBlock getblock("http_get");    +			LLFastTimer _(FTM_PROCESS_HTTP_GET);  			mNode.get(LLHTTPNode::ResponsePtr(mResponse), context);  		}  		else if(verb == HTTP_VERB_PUT)  		{ -            LLPerfBlock putblock("http_put"); +			LLFastTimer _(FTM_PROCESS_HTTP_PUT);  			LLSD input;  			if (mNode.getContentType() == LLHTTPNode::CONTENT_TYPE_LLSD)  			{ @@ -198,7 +203,7 @@ LLIOPipe::EStatus LLHTTPPipe::process_impl(  		}  		else if(verb == HTTP_VERB_POST)  		{ -            LLPerfBlock postblock("http_post"); +			LLFastTimer _(FTM_PROCESS_HTTP_POST);  			LLSD input;  			if (mNode.getContentType() == LLHTTPNode::CONTENT_TYPE_LLSD)  			{ @@ -214,7 +219,7 @@ LLIOPipe::EStatus LLHTTPPipe::process_impl(  		}  		else if(verb == HTTP_VERB_DELETE)  		{ -            LLPerfBlock delblock("http_delete"); +			LLFastTimer _(FTM_PROCESS_HTTP_DELETE);  			mNode.del(LLHTTPNode::ResponsePtr(mResponse), context);  		}		  		else if(verb == HTTP_VERB_OPTIONS) diff --git a/indra/llmessage/llmessagetemplate.h b/indra/llmessage/llmessagetemplate.h index 16d825d33b..a2024166ee 100644 --- a/indra/llmessage/llmessagetemplate.h +++ b/indra/llmessage/llmessagetemplate.h @@ -263,6 +263,7 @@ enum EMsgDeprecation  	MD_DEPRECATED  }; +  class LLMessageTemplate  {  public: @@ -364,7 +365,6 @@ public:  	{  		if (mHandlerFunc)  		{ -            LLPerfBlock msg_cb_time("msg_cb", mName);  			mHandlerFunc(msgsystem, mUserData);  			return TRUE;  		} diff --git a/indra/llmessage/llpumpio.cpp b/indra/llmessage/llpumpio.cpp index f3ef4f2684..fcb77a23a9 100644 --- a/indra/llmessage/llpumpio.cpp +++ b/indra/llmessage/llpumpio.cpp @@ -441,6 +441,7 @@ void LLPumpIO::pump()  }  static LLFastTimer::DeclareTimer FTM_PUMP_IO("Pump IO"); +static LLFastTimer::DeclareTimer FTM_PUMP_POLL("Pump Poll");  LLPumpIO::current_chain_t LLPumpIO::removeRunningChain(LLPumpIO::current_chain_t& run_chain)   { @@ -536,7 +537,7 @@ void LLPumpIO::pump(const S32& poll_timeout)  		S32 count = 0;  		S32 client_id = 0;          { -            LLPerfBlock polltime("pump_poll"); +			LLFastTimer _(FTM_PUMP_POLL);              apr_pollset_poll(mPollset, poll_timeout, &count, &poll_fd);          }  		PUMP_DEBUG; diff --git a/indra/newview/app_settings/logcontrol.xml b/indra/newview/app_settings/logcontrol.xml index 8636ba1090..92a241857e 100644 --- a/indra/newview/app_settings/logcontrol.xml +++ b/indra/newview/app_settings/logcontrol.xml @@ -48,24 +48,6 @@  						-->  						</array>  				</map> -        <map> -          <key>level</key> -          <string>NONE</string> -          <key>functions</key> -          <array> -          </array> -          <key>classes</key> -          <array> -            <string>LLViewerStatsRecorder</string> -          </array> -          <key>files</key> -          <array> -          </array> -          <key>tags</key> -          <array> - -          </array> -        </map>        </array>  	</map>  </llsd> diff --git a/indra/newview/llfasttimerview.cpp b/indra/newview/llfasttimerview.cpp index 9664aa7dbe..c032d5d049 100644 --- a/indra/newview/llfasttimerview.cpp +++ b/indra/newview/llfasttimerview.cpp @@ -95,7 +95,6 @@ LLFastTimerView::LLFastTimerView(const LLSD& key)  	mHoverBarIndex = -1;  	FTV_NUM_TIMERS = LLFastTimer::NamedTimer::instanceCount();  	mPrintStats = -1;	 -	mAverageCyclesPerTimer = 0;  }  void LLFastTimerView::onPause() @@ -379,12 +378,6 @@ void LLFastTimerView::draw()  	S32 xleft = margin;  	S32 ytop = margin; -	mAverageCyclesPerTimer = LLFastTimer::sTimerCalls == 0  -		? 0  -		: llround(lerp((F32)mAverageCyclesPerTimer, (F32)(LLFastTimer::sTimerCycles / (U64)LLFastTimer::sTimerCalls), 0.1f)); -	LLFastTimer::sTimerCycles = 0; -	LLFastTimer::sTimerCalls = 0; -  	// Draw some help  	{ @@ -392,10 +385,6 @@ void LLFastTimerView::draw()  		y = height - ytop;  		texth = (S32)LLFontGL::getFontMonospace()->getLineHeight(); -#if TIME_FAST_TIMERS -		tdesc = llformat("Cycles per timer call: %d", mAverageCyclesPerTimer); -		LLFontGL::getFontMonospace()->renderUTF8(tdesc, 0, x, y, LLColor4::white, LLFontGL::LEFT, LLFontGL::TOP); -#else  		char modedesc[][32] = {  			"2 x Average ",  			"Max         ", @@ -419,7 +408,6 @@ void LLFastTimerView::draw()  		LLFontGL::getFontMonospace()->renderUTF8(std::string("[Right-Click log selected] [ALT-Click toggle counts] [ALT-SHIFT-Click sub hidden]"),  										 0, x, y, LLColor4::white, LLFontGL::LEFT, LLFontGL::TOP); -#endif  		y -= (texth + 2);  	} diff --git a/indra/newview/llfasttimerview.h b/indra/newview/llfasttimerview.h index a349e7ad4c..1fda91f173 100644 --- a/indra/newview/llfasttimerview.h +++ b/indra/newview/llfasttimerview.h @@ -90,7 +90,6 @@ private:  	S32 mHoverBarIndex;  	LLFrameTimer mHighlightTimer;  	S32 mPrintStats; -	S32 mAverageCyclesPerTimer;  	LLRect mGraphRect;  }; diff --git a/indra/newview/lltexturefetch.cpp b/indra/newview/lltexturefetch.cpp index 7e6dfbc9d9..143db79eb5 100755 --- a/indra/newview/lltexturefetch.cpp +++ b/indra/newview/lltexturefetch.cpp @@ -50,6 +50,7 @@  #include "llviewertexture.h"  #include "llviewerregion.h"  #include "llviewerstats.h" +#include "llviewerstatsrecorder.h"  #include "llviewerassetstats.h"  #include "llworld.h"  #include "llsdutil.h" @@ -1703,6 +1704,7 @@ S32 LLTextureFetchWorker::callbackHttpGet(const LLChannelDescriptors& channels,  		LL_DEBUGS("Texture") << "HTTP RECEIVED: " << mID.asString() << " Bytes: " << data_size << LL_ENDL;  		if (data_size > 0)  		{ +			LLViewerStatsRecorder::instance().textureFetch(data_size);  			// *TODO: set the formatted image data here directly to avoid the copy  			mBuffer = (U8*)ALLOCATE_MEM(LLImageBase::getPrivatePool(), data_size);  			buffer->readAfter(channels.in(), NULL, mBuffer, data_size); @@ -1736,6 +1738,7 @@ S32 LLTextureFetchWorker::callbackHttpGet(const LLChannelDescriptors& channels,  	mLoaded = TRUE;  	setPriority(LLWorkerThread::PRIORITY_HIGH | mWorkPriority); +	LLViewerStatsRecorder::instance().log(0.2f);  	return data_size ;  } @@ -2639,6 +2642,9 @@ bool LLTextureFetch::receiveImageHeader(const LLHost& host, const LLUUID& id, U8  		return false;  	} +	LLViewerStatsRecorder::instance().textureFetch(data_size); +	LLViewerStatsRecorder::instance().log(0.1f); +  	worker->lockWorkMutex();  	//	Copy header data into image object @@ -2685,6 +2691,9 @@ bool LLTextureFetch::receiveImagePacket(const LLHost& host, const LLUUID& id, U1  		return false;  	} +	LLViewerStatsRecorder::instance().textureFetch(data_size); +	LLViewerStatsRecorder::instance().log(0.1f); +  	worker->lockWorkMutex();  	res = worker->insertPacket(packet_num, data, data_size); diff --git a/indra/newview/llviewerobjectlist.cpp b/indra/newview/llviewerobjectlist.cpp index b010ac9aa7..5a23b55fa7 100644 --- a/indra/newview/llviewerobjectlist.cpp +++ b/indra/newview/llviewerobjectlist.cpp @@ -347,9 +347,6 @@ void LLViewerObjectList::processObjectUpdate(LLMessageSystem *mesgsys,  	LLDataPackerBinaryBuffer compressed_dp(compressed_dpbuffer, 2048);  	LLDataPacker *cached_dpp = NULL;  	LLViewerStatsRecorder& recorder = LLViewerStatsRecorder::instance(); -#if LL_RECORD_VIEWER_STATS -	recorder.beginObjectUpdateEvents(1.f); -#endif  	for (i = 0; i < num_objects; i++)  	{ @@ -380,9 +377,7 @@ void LLViewerObjectList::processObjectUpdate(LLMessageSystem *mesgsys,  			else  			{  				// Cache Miss. -#if LL_RECORD_VIEWER_STATS -				recorder.recordCacheMissEvent(id, update_type, cache_miss_type, msg_size); -#endif +				recorder.cacheMissEvent(id, update_type, cache_miss_type, msg_size);  				continue; // no data packer, skip this object  			} @@ -509,9 +504,7 @@ void LLViewerObjectList::processObjectUpdate(LLMessageSystem *mesgsys,  				if (update_type == OUT_TERSE_IMPROVED)  				{  					// llinfos << "terse update for an unknown object (compressed):" << fullid << llendl; -					#if LL_RECORD_VIEWER_STATS -					recorder.recordObjectUpdateFailure(local_id, update_type, msg_size); -					#endif +					recorder.objectUpdateFailure(local_id, update_type, msg_size);  					continue;  				}  			} @@ -523,9 +516,7 @@ void LLViewerObjectList::processObjectUpdate(LLMessageSystem *mesgsys,  				if (update_type != OUT_FULL)  				{  					//llinfos << "terse update for an unknown object:" << fullid << llendl; -					#if LL_RECORD_VIEWER_STATS -					recorder.recordObjectUpdateFailure(local_id, update_type, msg_size); -					#endif +					recorder.objectUpdateFailure(local_id, update_type, msg_size);  					continue;  				} @@ -538,9 +529,7 @@ void LLViewerObjectList::processObjectUpdate(LLMessageSystem *mesgsys,  			{  				mNumDeadObjectUpdates++;  				//llinfos << "update for a dead object:" << fullid << llendl; -				#if LL_RECORD_VIEWER_STATS -				recorder.recordObjectUpdateFailure(local_id, update_type, msg_size); -				#endif +				recorder.objectUpdateFailure(local_id, update_type, msg_size);  				continue;  			}  #endif @@ -549,9 +538,7 @@ void LLViewerObjectList::processObjectUpdate(LLMessageSystem *mesgsys,  			if (!objectp)  			{  				llinfos << "createObject failure for object: " << fullid << llendl; -				#if LL_RECORD_VIEWER_STATS -				recorder.recordObjectUpdateFailure(local_id, update_type, msg_size); -				#endif +				recorder.objectUpdateFailure(local_id, update_type, msg_size);  				continue;  			}  			justCreated = TRUE; @@ -577,12 +564,8 @@ void LLViewerObjectList::processObjectUpdate(LLMessageSystem *mesgsys,  			if (update_type != OUT_TERSE_IMPROVED) // OUT_FULL_COMPRESSED only?  			{  				bCached = true; -				#if LL_RECORD_VIEWER_STATS  				LLViewerRegion::eCacheUpdateResult result = objectp->mRegionp->cacheFullUpdate(objectp, compressed_dp); -				recorder.recordCacheFullUpdate(local_id, update_type, result, objectp, msg_size); -				#else -				objectp->mRegionp->cacheFullUpdate(objectp, compressed_dp); -				#endif +				recorder.cacheFullUpdate(local_id, update_type, result, objectp, msg_size);  			}  		}  		else if (cached) // Cache hit only? @@ -598,16 +581,12 @@ void LLViewerObjectList::processObjectUpdate(LLMessageSystem *mesgsys,  			}  			processUpdateCore(objectp, user_data, i, update_type, NULL, justCreated);  		} -		#if LL_RECORD_VIEWER_STATS -		recorder.recordObjectUpdateEvent(local_id, update_type, objectp, msg_size); -		#endif +		recorder.objectUpdateEvent(local_id, update_type, objectp, msg_size);  		objectp->setLastUpdateType(update_type);  		objectp->setLastUpdateCached(bCached);  	} -#if LL_RECORD_VIEWER_STATS -	recorder.endObjectUpdateEvents(); -#endif +	recorder.log(0.2f);  	LLVOAvatar::cullAvatarsByPixelArea();  } diff --git a/indra/newview/llviewerregion.cpp b/indra/newview/llviewerregion.cpp index 0e2927cea4..44377b1f3e 100644 --- a/indra/newview/llviewerregion.cpp +++ b/indra/newview/llviewerregion.cpp @@ -1317,11 +1317,8 @@ void LLViewerRegion::requestCacheMisses()  	mCacheDirty = TRUE ;  	// llinfos << "KILLDEBUG Sent cache miss full " << full_count << " crc " << crc_count << llendl; -	#if LL_RECORD_VIEWER_STATS -	LLViewerStatsRecorder::instance().beginObjectUpdateEvents(1.f); -	LLViewerStatsRecorder::instance().recordRequestCacheMissesEvent(full_count + crc_count); -	LLViewerStatsRecorder::instance().endObjectUpdateEvents(); -	#endif +	LLViewerStatsRecorder::instance().requestCacheMissesEvent(full_count + crc_count); +	LLViewerStatsRecorder::instance().log(0.2f);  }  void LLViewerRegion::dumpCache() diff --git a/indra/newview/llviewerstats.cpp b/indra/newview/llviewerstats.cpp index 497e95c5e3..c1ccfe3faa 100644 --- a/indra/newview/llviewerstats.cpp +++ b/indra/newview/llviewerstats.cpp @@ -323,55 +323,55 @@ void LLViewerStats::updateFrameStats(const F64 time_diff)  {  	if (mPacketsLostPercentStat.getCurrent() > 5.0)  	{ -		incStat(LLViewerStats::ST_LOSS_05_SECONDS, time_diff); +		incStat(ST_LOSS_05_SECONDS, time_diff);  	}  	if (mSimFPS.getCurrent() < 20.f && mSimFPS.getCurrent() > 0.f)  	{ -		incStat(LLViewerStats::ST_SIM_FPS_20_SECONDS, time_diff); +		incStat(ST_SIM_FPS_20_SECONDS, time_diff);  	}  	if (mSimPhysicsFPS.getCurrent() < 20.f && mSimPhysicsFPS.getCurrent() > 0.f)  	{ -		incStat(LLViewerStats::ST_PHYS_FPS_20_SECONDS, time_diff); +		incStat(ST_PHYS_FPS_20_SECONDS, time_diff);  	}  	if (time_diff >= 0.5)  	{ -		incStat(LLViewerStats::ST_FPS_2_SECONDS, time_diff); +		incStat(ST_FPS_2_SECONDS, time_diff);  	}  	if (time_diff >= 0.125)  	{ -		incStat(LLViewerStats::ST_FPS_8_SECONDS, time_diff); +		incStat(ST_FPS_8_SECONDS, time_diff);  	}  	if (time_diff >= 0.1)  	{ -		incStat(LLViewerStats::ST_FPS_10_SECONDS, time_diff); +		incStat(ST_FPS_10_SECONDS, time_diff);  	}  	if (gFrameCount && mLastTimeDiff > 0.0)  	{  		// new "stutter" meter -		setStat(LLViewerStats::ST_FPS_DROP_50_RATIO, -				(getStat(LLViewerStats::ST_FPS_DROP_50_RATIO) * (F64)(gFrameCount - 1) +  +		setStat(ST_FPS_DROP_50_RATIO, +				(getStat(ST_FPS_DROP_50_RATIO) * (F64)(gFrameCount - 1) +   				 (time_diff >= 2.0 * mLastTimeDiff ? 1.0 : 0.0)) / gFrameCount);  		// old stats that were never really used -		setStat(LLViewerStats::ST_FRAMETIME_JITTER, -				(getStat(LLViewerStats::ST_FRAMETIME_JITTER) * (gFrameCount - 1) +  +		setStat(ST_FRAMETIME_JITTER, +				(getStat(ST_FRAMETIME_JITTER) * (gFrameCount - 1) +   				 fabs(mLastTimeDiff - time_diff) / mLastTimeDiff) / gFrameCount);  		F32 average_frametime = gRenderStartTime.getElapsedTimeF32() / (F32)gFrameCount; -		setStat(LLViewerStats::ST_FRAMETIME_SLEW, -				(getStat(LLViewerStats::ST_FRAMETIME_SLEW) * (gFrameCount - 1) +  +		setStat(ST_FRAMETIME_SLEW, +				(getStat(ST_FRAMETIME_SLEW) * (gFrameCount - 1) +   				 fabs(average_frametime - time_diff) / average_frametime) / gFrameCount);  		F32 max_bandwidth = gViewerThrottle.getMaxBandwidth();  		F32 delta_bandwidth = gViewerThrottle.getCurrentBandwidth() - max_bandwidth; -		setStat(LLViewerStats::ST_DELTA_BANDWIDTH, delta_bandwidth / 1024.f); +		setStat(ST_DELTA_BANDWIDTH, delta_bandwidth / 1024.f); -		setStat(LLViewerStats::ST_MAX_BANDWIDTH, max_bandwidth / 1024.f); +		setStat(ST_MAX_BANDWIDTH, max_bandwidth / 1024.f);  	} @@ -399,19 +399,6 @@ void LLViewerStats::addToMessage(LLSD &body) const  			<< "; Count = " << mAgentPositionSnaps.getCount() << llendl;  } -// static -// const std::string LLViewerStats::statTypeToText(EStatType type) -// { -// 	if (type >= 0 && type < ST_COUNT) -// 	{ -// 		return STAT_INFO[type].mName; -// 	} -// 	else -// 	{ -// 		return "Unknown statistic"; -// 	} -// } -  // *NOTE:Mani The following methods used to exist in viewer.cpp  // Moving them here, but not merging them into LLViewerStats yet.  void reset_statistics() @@ -579,6 +566,8 @@ void update_statistics(U32 frame_count)  	gTotalWorldBytes += gVLManager.getTotalBytes();  	gTotalObjectBytes += gObjectBits / 8; +	LLViewerStats& stats = LLViewerStats::instance(); +  	// make sure we have a valid time delta for this frame  	if (gFrameIntervalSeconds > 0.f)  	{ @@ -595,42 +584,42 @@ void update_statistics(U32 frame_count)  			LLViewerStats::getInstance()->incStat(LLViewerStats::ST_TOOLBOX_SECONDS, gFrameIntervalSeconds);  		}  	} -	LLViewerStats::getInstance()->setStat(LLViewerStats::ST_ENABLE_VBO, (F64)gSavedSettings.getBOOL("RenderVBOEnable")); -	LLViewerStats::getInstance()->setStat(LLViewerStats::ST_LIGHTING_DETAIL, (F64)gPipeline.getLightingDetail()); -	LLViewerStats::getInstance()->setStat(LLViewerStats::ST_DRAW_DIST, (F64)gSavedSettings.getF32("RenderFarClip")); -	LLViewerStats::getInstance()->setStat(LLViewerStats::ST_CHAT_BUBBLES, (F64)gSavedSettings.getBOOL("UseChatBubbles")); +	stats.setStat(LLViewerStats::ST_ENABLE_VBO, (F64)gSavedSettings.getBOOL("RenderVBOEnable")); +	stats.setStat(LLViewerStats::ST_LIGHTING_DETAIL, (F64)gPipeline.getLightingDetail()); +	stats.setStat(LLViewerStats::ST_DRAW_DIST, (F64)gSavedSettings.getF32("RenderFarClip")); +	stats.setStat(LLViewerStats::ST_CHAT_BUBBLES, (F64)gSavedSettings.getBOOL("UseChatBubbles"));  #if 0 // 1.9.2 -	LLViewerStats::getInstance()->setStat(LLViewerStats::ST_SHADER_OBJECTS, (F64)gSavedSettings.getS32("VertexShaderLevelObject")); -	LLViewerStats::getInstance()->setStat(LLViewerStats::ST_SHADER_AVATAR, (F64)gSavedSettings.getBOOL("VertexShaderLevelAvatar")); -	LLViewerStats::getInstance()->setStat(LLViewerStats::ST_SHADER_ENVIRONMENT, (F64)gSavedSettings.getBOOL("VertexShaderLevelEnvironment")); +	stats.setStat(LLViewerStats::ST_SHADER_OBJECTS, (F64)gSavedSettings.getS32("VertexShaderLevelObject")); +	stats.setStat(LLViewerStats::ST_SHADER_AVATAR, (F64)gSavedSettings.getBOOL("VertexShaderLevelAvatar")); +	stats.setStat(LLViewerStats::ST_SHADER_ENVIRONMENT, (F64)gSavedSettings.getBOOL("VertexShaderLevelEnvironment"));  #endif -	LLViewerStats::getInstance()->setStat(LLViewerStats::ST_FRAME_SECS, gDebugView->mFastTimerView->getTime("Frame")); +	stats.setStat(LLViewerStats::ST_FRAME_SECS, gDebugView->mFastTimerView->getTime("Frame"));  	F64 idle_secs = gDebugView->mFastTimerView->getTime("Idle");  	F64 network_secs = gDebugView->mFastTimerView->getTime("Network"); -	LLViewerStats::getInstance()->setStat(LLViewerStats::ST_UPDATE_SECS, idle_secs - network_secs); -	LLViewerStats::getInstance()->setStat(LLViewerStats::ST_NETWORK_SECS, network_secs); -	LLViewerStats::getInstance()->setStat(LLViewerStats::ST_IMAGE_SECS, gDebugView->mFastTimerView->getTime("Update Images")); -	LLViewerStats::getInstance()->setStat(LLViewerStats::ST_REBUILD_SECS, gDebugView->mFastTimerView->getTime("Sort Draw State")); -	LLViewerStats::getInstance()->setStat(LLViewerStats::ST_RENDER_SECS, gDebugView->mFastTimerView->getTime("Geometry")); +	stats.setStat(LLViewerStats::ST_UPDATE_SECS, idle_secs - network_secs); +	stats.setStat(LLViewerStats::ST_NETWORK_SECS, network_secs); +	stats.setStat(LLViewerStats::ST_IMAGE_SECS, gDebugView->mFastTimerView->getTime("Update Images")); +	stats.setStat(LLViewerStats::ST_REBUILD_SECS, gDebugView->mFastTimerView->getTime("Sort Draw State")); +	stats.setStat(LLViewerStats::ST_RENDER_SECS, gDebugView->mFastTimerView->getTime("Geometry"));  	LLCircuitData *cdp = gMessageSystem->mCircuitInfo.findCircuit(gAgent.getRegion()->getHost());  	if (cdp)  	{ -		LLViewerStats::getInstance()->mSimPingStat.addValue(cdp->getPingDelay()); +		stats.mSimPingStat.addValue(cdp->getPingDelay());  		gAvgSimPing = ((gAvgSimPing * (F32)gSimPingCount) + (F32)(cdp->getPingDelay())) / ((F32)gSimPingCount + 1);  		gSimPingCount++;  	}  	else  	{ -		LLViewerStats::getInstance()->mSimPingStat.addValue(10000); +		stats.mSimPingStat.addValue(10000);  	} -	LLViewerStats::getInstance()->mFPSStat.addValue(1); +	stats.mFPSStat.addValue(1);  	F32 layer_bits = (F32)(gVLManager.getLandBits() + gVLManager.getWindBits() + gVLManager.getCloudBits()); -	LLViewerStats::getInstance()->mLayersKBitStat.addValue(layer_bits/1024.f); -	LLViewerStats::getInstance()->mObjectKBitStat.addValue(gObjectBits/1024.f); -	LLViewerStats::getInstance()->mVFSPendingOperations.addValue(LLVFile::getVFSThread()->getPending()); -	LLViewerStats::getInstance()->mAssetKBitStat.addValue(gTransferManager.getTransferBitsIn(LLTCT_ASSET)/1024.f); +	stats.mLayersKBitStat.addValue(layer_bits/1024.f); +	stats.mObjectKBitStat.addValue(gObjectBits/1024.f); +	stats.mVFSPendingOperations.addValue(LLVFile::getVFSThread()->getPending()); +	stats.mAssetKBitStat.addValue(gTransferManager.getTransferBitsIn(LLTCT_ASSET)/1024.f);  	gTransferManager.resetTransferBitsIn(LLTCT_ASSET);  	if (LLAppViewer::getTextureFetch()->getNumRequests() == 0) @@ -651,7 +640,7 @@ void update_statistics(U32 frame_count)  			visible_avatar_frames = 1.f;  			avg_visible_avatars = (avg_visible_avatars * (F32)(visible_avatar_frames - 1.f) + visible_avatars) / visible_avatar_frames;  		} -		LLViewerStats::getInstance()->setStat(LLViewerStats::ST_VISIBLE_AVATARS, (F64)avg_visible_avatars); +		stats.setStat(LLViewerStats::ST_VISIBLE_AVATARS, (F64)avg_visible_avatars);  	}  	LLWorld::getInstance()->updateNetStats();  	LLWorld::getInstance()->requestCacheMisses(); @@ -667,8 +656,8 @@ void update_statistics(U32 frame_count)  		static LLFrameTimer texture_stats_timer;  		if (texture_stats_timer.getElapsedTimeF32() >= texture_stats_freq)  		{ -			LLViewerStats::getInstance()->mTextureKBitStat.addValue(LLViewerTextureList::sTextureBits/1024.f); -			LLViewerStats::getInstance()->mTexturePacketsStat.addValue(LLViewerTextureList::sTexturePackets); +			stats.mTextureKBitStat.addValue(LLViewerTextureList::sTextureBits/1024.f); +			stats.mTexturePacketsStat.addValue(LLViewerTextureList::sTexturePackets);  			gTotalTextureBytes += LLViewerTextureList::sTextureBits / 8;  			LLViewerTextureList::sTextureBits = 0;  			LLViewerTextureList::sTexturePackets = 0; diff --git a/indra/newview/llviewerstats.h b/indra/newview/llviewerstats.h index 750d963f69..9a2a33fa7b 100644 --- a/indra/newview/llviewerstats.h +++ b/indra/newview/llviewerstats.h @@ -112,8 +112,7 @@ public:  	void resetStats();  public: -	// If you change this, please also add a corresponding text label -	// in statTypeToText in llviewerstats.cpp +	// If you change this, please also add a corresponding text label in llviewerstats.cpp  	enum EStatType  	{  		ST_VERSION = 0, diff --git a/indra/newview/llviewerstatsrecorder.cpp b/indra/newview/llviewerstatsrecorder.cpp index cfb446fe45..91e485d01b 100644 --- a/indra/newview/llviewerstatsrecorder.cpp +++ b/indra/newview/llviewerstatsrecorder.cpp @@ -27,7 +27,6 @@  #include "llviewerprecompiledheaders.h"  #include "llviewerstatsrecorder.h" -#if LL_RECORD_VIEWER_STATS  #include "llfile.h"  #include "llviewerregion.h" @@ -46,8 +45,6 @@ LLViewerStatsRecorder::LLViewerStatsRecorder() :  	mObjectCacheFile(NULL),  	mTimer(),  	mStartTime(0.0), -	mProcessingStartTime(0.0), -	mProcessingTotalTime(0.0),  	mLastSnapshotTime(0.0)  {  	if (NULL != sInstance) @@ -63,50 +60,12 @@ LLViewerStatsRecorder::~LLViewerStatsRecorder()  	if (mObjectCacheFile != NULL)  	{  		// last chance snapshot -		takeSnapshot(); +		writeToLog(0.f);  		LLFile::close(mObjectCacheFile);  		mObjectCacheFile = NULL;  	}  } -void LLViewerStatsRecorder::beginObjectUpdateEvents(F32 interval) -{ -	mSnapshotInterval = interval; -	if (mObjectCacheFile == NULL) -	{ -		mStartTime = LLTimer::getTotalSeconds(); -		mObjectCacheFile = LLFile::fopen(STATS_FILE_NAME, "wb"); -		if (mObjectCacheFile) -		{	// Write column headers -			std::ostringstream data_msg; -			data_msg << "EventTime(ms), " -				<< "Processing Time(ms), " -				<< "Cache Hits, " -				<< "Cache Full Misses, " -				<< "Cache Crc Misses, " -				<< "Full Updates, " -				<< "Terse Updates, " -				<< "Cache Miss Requests, " -				<< "Cache Miss Responses, " -				<< "Cache Update Dupes, " -				<< "Cache Update Changes, " -				<< "Cache Update Adds, " -				<< "Cache Update Replacements, " -				<< "Update Failures, " -				<< "Cache Hits bps, " -				<< "Cache Full Misses bps, " -				<< "Cache Crc Misses bps, " -				<< "Full Updates bps, " -				<< "Terse Updates bps, " -				<< "Cache Miss Responses bps, " -				<< "\n"; - -			fwrite(data_msg.str().c_str(), 1, data_msg.str().size(), mObjectCacheFile ); -		} -	} -	mProcessingStartTime = LLTimer::getTotalSeconds(); -} -  void LLViewerStatsRecorder::clearStats()  {  	mObjectCacheHitCount = 0; @@ -128,6 +87,7 @@ void LLViewerStatsRecorder::clearStats()  	mObjectCacheUpdateReplacements = 0;  	mObjectUpdateFailures = 0;  	mObjectUpdateFailuresSize = 0; +	mTextureFetchSize = 0;  } @@ -204,69 +164,93 @@ void LLViewerStatsRecorder::recordRequestCacheMissesEvent(S32 count)  	mObjectCacheMissRequests += count;  } -void LLViewerStatsRecorder::endObjectUpdateEvents() -{ -	mProcessingTotalTime += LLTimer::getTotalSeconds() - mProcessingStartTime; -	takeSnapshot(); -} - -void LLViewerStatsRecorder::takeSnapshot() +void LLViewerStatsRecorder::writeToLog( F32 interval )  {  	F64 delta_time = LLTimer::getTotalSeconds() - mLastSnapshotTime; -	if ( delta_time > mSnapshotInterval) -	{ -		mLastSnapshotTime = LLTimer::getTotalSeconds(); -		llinfos << "ILX: "  -			<< mObjectCacheHitCount << " hits, "  -			<< mObjectCacheMissFullCount << " full misses, " -			<< mObjectCacheMissCrcCount << " crc misses, " -			<< mObjectFullUpdates << " full updates, " -			<< mObjectTerseUpdates << " terse updates, " -			<< mObjectCacheMissRequests << " cache miss requests, " -			<< mObjectCacheMissResponses << " cache miss responses, " -			<< mObjectCacheUpdateDupes << " cache update dupes, " -			<< mObjectCacheUpdateChanges << " cache update changes, " -			<< mObjectCacheUpdateAdds << " cache update adds, " -			<< mObjectCacheUpdateReplacements << " cache update replacements, " -			<< mObjectUpdateFailures << " update failures" -			<< llendl; +	S32 total_objects = mObjectCacheHitCount + mObjectCacheMissCrcCount + mObjectCacheMissFullCount + mObjectFullUpdates + mObjectTerseUpdates + mObjectCacheMissRequests + mObjectCacheMissResponses + mObjectCacheUpdateDupes + mObjectCacheUpdateChanges + mObjectCacheUpdateAdds + mObjectCacheUpdateReplacements + mObjectUpdateFailures; -		S32 total_objects = mObjectCacheHitCount + mObjectCacheMissCrcCount + mObjectCacheMissFullCount + mObjectFullUpdates + mObjectTerseUpdates + mObjectCacheMissRequests + mObjectCacheMissResponses + mObjectCacheUpdateDupes + mObjectCacheUpdateChanges + mObjectCacheUpdateAdds + mObjectCacheUpdateReplacements + mObjectUpdateFailures; -		if (mObjectCacheFile != NULL && -			total_objects > 0) -		{ -			std::ostringstream data_msg; +	if ( delta_time < interval || total_objects == 0) return; -			F32 processing32 = (F32) mProcessingTotalTime; -			mProcessingTotalTime = 0.0; +	mLastSnapshotTime = LLTimer::getTotalSeconds(); +	lldebugs << "ILX: "  +		<< mObjectCacheHitCount << " hits, "  +		<< mObjectCacheMissFullCount << " full misses, " +		<< mObjectCacheMissCrcCount << " crc misses, " +		<< mObjectFullUpdates << " full updates, " +		<< mObjectTerseUpdates << " terse updates, " +		<< mObjectCacheMissRequests << " cache miss requests, " +		<< mObjectCacheMissResponses << " cache miss responses, " +		<< mObjectCacheUpdateDupes << " cache update dupes, " +		<< mObjectCacheUpdateChanges << " cache update changes, " +		<< mObjectCacheUpdateAdds << " cache update adds, " +		<< mObjectCacheUpdateReplacements << " cache update replacements, " +		<< mObjectUpdateFailures << " update failures" +		<< llendl; -			data_msg << getTimeSinceStart() -				<< ", " << processing32 -				<< ", " << mObjectCacheHitCount -				<< ", " << mObjectCacheMissFullCount -				<< ", " << mObjectCacheMissCrcCount -				<< ", " << mObjectFullUpdates -				<< ", " << mObjectTerseUpdates -				<< ", " << mObjectCacheMissRequests -				<< ", " << mObjectCacheMissResponses -				<< ", " << mObjectCacheUpdateDupes -				<< ", " << mObjectCacheUpdateChanges -				<< ", " << mObjectCacheUpdateAdds -				<< ", " << mObjectCacheUpdateReplacements -				<< ", " << mObjectUpdateFailures -				<< ", " << (mObjectCacheHitSize * 8 / delta_time) -				<< ", " << (mObjectCacheMissFullSize * 8 / delta_time) -				<< ", " << (mObjectCacheMissCrcSize * 8 / delta_time) -				<< ", " << (mObjectFullUpdatesSize * 8 / delta_time) -				<< ", " << (mObjectTerseUpdatesSize * 8 / delta_time) -				<< ", " << (mObjectCacheMissResponsesSize * 8 / delta_time) +	if (mObjectCacheFile == NULL) +	{ +		mStartTime = LLTimer::getTotalSeconds(); +		mObjectCacheFile = LLFile::fopen(STATS_FILE_NAME, "wb"); +		if (mObjectCacheFile) +		{	// Write column headers +			std::ostringstream data_msg; +			data_msg << "EventTime(ms)\t" +				<< "Cache Hits\t" +				<< "Cache Full Misses\t" +				<< "Cache Crc Misses\t" +				<< "Full Updates\t" +				<< "Terse Updates\t" +				<< "Cache Miss Requests\t" +				<< "Cache Miss Responses\t" +				<< "Cache Update Dupes\t" +				<< "Cache Update Changes\t" +				<< "Cache Update Adds\t" +				<< "Cache Update Replacements\t" +				<< "Update Failures\t" +				<< "Cache Hits bps\t" +				<< "Cache Full Misses bps\t" +				<< "Cache Crc Misses bps\t" +				<< "Full Updates bps\t" +				<< "Terse Updates bps\t" +				<< "Cache Miss Responses bps\t" +				<< "Texture Fetch bps\t"  				<< "\n";  			fwrite(data_msg.str().c_str(), 1, data_msg.str().size(), mObjectCacheFile );  		} - -		clearStats(); +		else +		{ +			llwarns << "Couldn't open " << STATS_FILE_NAME << " for logging." << llendl; +			return; +		}  	} + +	std::ostringstream data_msg; + +	data_msg << getTimeSinceStart() +		<< "\t " << mObjectCacheHitCount +		<< "\t" << mObjectCacheMissFullCount +		<< "\t" << mObjectCacheMissCrcCount +		<< "\t" << mObjectFullUpdates +		<< "\t" << mObjectTerseUpdates +		<< "\t" << mObjectCacheMissRequests +		<< "\t" << mObjectCacheMissResponses +		<< "\t" << mObjectCacheUpdateDupes +		<< "\t" << mObjectCacheUpdateChanges +		<< "\t" << mObjectCacheUpdateAdds +		<< "\t" << mObjectCacheUpdateReplacements +		<< "\t" << mObjectUpdateFailures +		<< "\t" << (mObjectCacheHitSize * 8 / delta_time) +		<< "\t" << (mObjectCacheMissFullSize * 8 / delta_time) +		<< "\t" << (mObjectCacheMissCrcSize * 8 / delta_time) +		<< "\t" << (mObjectFullUpdatesSize * 8 / delta_time) +		<< "\t" << (mObjectTerseUpdatesSize * 8 / delta_time) +		<< "\t" << (mObjectCacheMissResponsesSize * 8 / delta_time) +		<< "\t" << (mTextureFetchSize * 8 / delta_time) +		<< "\n"; + +	fwrite(data_msg.str().c_str(), 1, data_msg.str().size(), mObjectCacheFile ); +	clearStats();  }  F32 LLViewerStatsRecorder::getTimeSinceStart() @@ -274,7 +258,10 @@ F32 LLViewerStatsRecorder::getTimeSinceStart()  	return (F32) (LLTimer::getTotalSeconds() - mStartTime);  } -#endif +void LLViewerStatsRecorder::recordTextureFetch( S32 msg_size ) +{ +	mTextureFetchSize += msg_size; +} diff --git a/indra/newview/llviewerstatsrecorder.h b/indra/newview/llviewerstatsrecorder.h index 09530b13eb..ce6dd63ec5 100644 --- a/indra/newview/llviewerstatsrecorder.h +++ b/indra/newview/llviewerstatsrecorder.h @@ -35,7 +35,6 @@  #define LL_RECORD_VIEWER_STATS	1 -#if LL_RECORD_VIEWER_STATS  #include "llframetimer.h"  #include "llviewerobject.h"  #include "llviewerregion.h" @@ -50,29 +49,71 @@ class LLViewerStatsRecorder : public LLSingleton<LLViewerStatsRecorder>  	LLViewerStatsRecorder();  	~LLViewerStatsRecorder(); -	void beginObjectUpdateEvents(F32 interval); +	void objectUpdateFailure(U32 local_id, const EObjectUpdateType update_type, S32 msg_size) +	{ +#if LL_RECORD_VIEWER_STATS +		recordObjectUpdateFailure(local_id, update_type, msg_size); +#endif +	} + +	void cacheMissEvent(U32 local_id, const EObjectUpdateType update_type, U8 cache_miss_type, S32 msg_size) +	{ +#if LL_RECORD_VIEWER_STATS +		recordCacheMissEvent(local_id, update_type, cache_miss_type, msg_size); +#endif +	} + +	void objectUpdateEvent(U32 local_id, const EObjectUpdateType update_type, LLViewerObject * objectp, S32 msg_size) +	{ +#if LL_RECORD_VIEWER_STATS +		recordObjectUpdateEvent(local_id, update_type, objectp, msg_size); +#endif +	} +	void cacheFullUpdate(U32 local_id, const EObjectUpdateType update_type, LLViewerRegion::eCacheUpdateResult update_result, LLViewerObject* objectp, S32 msg_size) +	{ +#if LL_RECORD_VIEWER_STATS +		recordCacheFullUpdate(local_id, update_type, update_result, objectp, msg_size); +#endif +	} + +	void requestCacheMissesEvent(S32 count) +	{ +#if LL_RECORD_VIEWER_STATS +		recordRequestCacheMissesEvent(count); +#endif +	} + +	void textureFetch(S32 msg_size) +	{ +#if LL_RECORD_VIEWER_STATS +		recordTextureFetch(msg_size); +#endif +	} + +	void log(F32 interval) +	{ +#if LL_RECORD_VIEWER_STATS +		writeToLog(interval); +#endif +	} + +	F32 getTimeSinceStart(); + +private:  	void recordObjectUpdateFailure(U32 local_id, const EObjectUpdateType update_type, S32 msg_size);  	void recordCacheMissEvent(U32 local_id, const EObjectUpdateType update_type, U8 cache_miss_type, S32 msg_size);  	void recordObjectUpdateEvent(U32 local_id, const EObjectUpdateType update_type, LLViewerObject * objectp, S32 msg_size);  	void recordCacheFullUpdate(U32 local_id, const EObjectUpdateType update_type, LLViewerRegion::eCacheUpdateResult update_result, LLViewerObject* objectp, S32 msg_size);  	void recordRequestCacheMissesEvent(S32 count); -	 -	void endObjectUpdateEvents(); - -	F32 getTimeSinceStart(); - -private: -	void takeSnapshot(); +	void recordTextureFetch(S32 msg_size); +	void writeToLog(F32 interval);  	static LLViewerStatsRecorder* sInstance;  	LLFILE *	mObjectCacheFile;		// File to write data into  	LLFrameTimer	mTimer;  	F64			mStartTime; -	F64			mProcessingStartTime; -	F64			mProcessingTotalTime; -	F64			mSnapshotInterval;  	F64			mLastSnapshotTime;  	S32			mObjectCacheHitCount; @@ -94,11 +135,11 @@ private:  	S32			mObjectCacheUpdateReplacements;  	S32			mObjectUpdateFailures;  	S32			mObjectUpdateFailuresSize; +	S32			mTextureFetchSize;  	void	clearStats();  }; -#endif	// LL_RECORD_VIEWER_STATS  #endif // LLVIEWERSTATSRECORDER_H | 
