Merge branch 'master' (DRTVWR-557) into DRTVWR-546

# Conflicts:
#	autobuild.xml
#	doc/contributions.txt
#	indra/cmake/GLOD.cmake
#	indra/llcommon/tests/llprocess_test.cpp
#	indra/newview/VIEWER_VERSION.txt
#	indra/newview/lldrawpoolavatar.cpp
#	indra/newview/llfloatermodelpreview.cpp
#	indra/newview/llmodelpreview.cpp
#	indra/newview/llviewertexturelist.cpp
#	indra/newview/llvovolume.cpp
#	indra/newview/viewer_manifest.py

1 files changed, 151 insertions, 34 deletions

diff --git a/indra/newview/lltexturefetch.cpp b/indra/newview/lltexturefetch.cpp
index 73a25397fd..0edaf40c66 100644
--- a/indra/newview/lltexturefetch.cpp
+++ b/indra/newview/lltexturefetch.cpp
@@ -70,8 +70,12 @@ LLTrace::EventStatHandle<LLUnit<F32, LLUnits::Percent> > LLTextureFetch::sCacheH
 
 LLTrace::SampleStatHandle<F32Seconds> LLTextureFetch::sCacheReadLatency("texture_cache_read_latency");
 LLTrace::SampleStatHandle<F32Seconds> LLTextureFetch::sTexDecodeLatency("texture_decode_latency");
+LLTrace::SampleStatHandle<F32Seconds> LLTextureFetch::sCacheWriteLatency("texture_write_latency");
 LLTrace::SampleStatHandle<F32Seconds> LLTextureFetch::sTexFetchLatency("texture_fetch_latency");
 
+LLTextureFetchTester* LLTextureFetch::sTesterp = NULL ;
+const std::string sTesterName("TextureFetchTester");
+
 //////////////////////////////////////////////////////////////////////////////
 //
 // Introduction
@@ -441,6 +445,29 @@ public:
 	// Threads:  Ttf
 	virtual void onCompleted(LLCore::HttpHandle handle, LLCore::HttpResponse * response);
 
+	enum e_state // mState
+	{
+		// *NOTE:  Do not change the order/value of state variables, some code
+		// depends upon specific ordering/adjacency.
+
+		// NOTE: Affects LLTextureBar::draw in lltextureview.cpp (debug hack)
+		INVALID = 0,
+		INIT,
+		LOAD_FROM_TEXTURE_CACHE,
+		CACHE_POST,
+		LOAD_FROM_NETWORK,
+		LOAD_FROM_SIMULATOR,
+		WAIT_HTTP_RESOURCE,				// Waiting for HTTP resources
+		WAIT_HTTP_RESOURCE2,			// Waiting for HTTP resources
+		SEND_HTTP_REQ,					// Commit to sending as HTTP
+		WAIT_HTTP_REQ,					// Request sent, wait for completion
+		DECODE_IMAGE,
+		DECODE_IMAGE_UPDATE,
+		WRITE_TO_CACHE,
+		WAIT_ON_WRITE,
+		DONE
+	};
+
 protected:
 	LLTextureFetchWorker(LLTextureFetch* fetcher, FTType f_type,
 						 const std::string& url, const LLUUID& id, const LLHost& host,
@@ -520,28 +547,6 @@ private:
 		}
 	
 private:
-	enum e_state // mState
-	{
-		// *NOTE:  Do not change the order/value of state variables, some code
-		// depends upon specific ordering/adjacency.
-		
-		// NOTE: Affects LLTextureBar::draw in lltextureview.cpp (debug hack)
-		INVALID = 0,
-		INIT,
-		LOAD_FROM_TEXTURE_CACHE,
-		CACHE_POST,
-		LOAD_FROM_NETWORK,
-		LOAD_FROM_SIMULATOR,
-		WAIT_HTTP_RESOURCE,				// Waiting for HTTP resources
-		WAIT_HTTP_RESOURCE2,			// Waiting for HTTP resources
-		SEND_HTTP_REQ,					// Commit to sending as HTTP
-		WAIT_HTTP_REQ,					// Request sent, wait for completion
-		DECODE_IMAGE,
-		DECODE_IMAGE_UPDATE,
-		WRITE_TO_CACHE,
-		WAIT_ON_WRITE,
-		DONE
-	};
 	enum e_request_state // mSentRequest
 	{
 		UNSENT = 0,
@@ -554,7 +559,7 @@ private:
 		CAN_WRITE = 1,
 		SHOULD_WRITE = 2
 	};
-	static const char* sStateDescs[];
+
 	e_state mState;
 	void setState(e_state new_state);
 
@@ -582,10 +587,15 @@ private:
 	LLFrameTimer mFetchDeltaTimer;
 	LLTimer mCacheReadTimer;
     LLTimer mDecodeTimer;
+	LLTimer mCacheWriteTimer;
     LLTimer mFetchTimer;
+	LLTimer mStateTimer;
 	F32 mCacheReadTime; // time for cache read only
     F32 mDecodeTime;    // time for decode only
+	F32 mCacheWriteTime;
     F32 mFetchTime;     // total time from req to finished fetch
+	std::map<S32, F32> mStateTimersMap;
+	F32 mSkippedStatesTime;
 	LLTextureCache::handle_t    mCacheReadHandle,
 								mCacheWriteHandle;
 	S32                         mRequestedSize,
@@ -869,8 +879,7 @@ bool truncate_viewer_metrics(int max_regions, LLSD & metrics);
 
 //////////////////////////////////////////////////////////////////////////////
 
-//static
-const char* LLTextureFetchWorker::sStateDescs[] = {
+const char* sStateDescs[] = {
 	"INVALID",
 	"INIT",
 	"LOAD_FROM_TEXTURE_CACHE",
@@ -888,6 +897,9 @@ const char* LLTextureFetchWorker::sStateDescs[] = {
 	"DONE"
 };
 
+const std::set<S32> LOGGED_STATES = { LLTextureFetchWorker::LOAD_FROM_TEXTURE_CACHE, LLTextureFetchWorker::LOAD_FROM_NETWORK, LLTextureFetchWorker::LOAD_FROM_SIMULATOR, 
+										LLTextureFetchWorker::WAIT_HTTP_REQ, LLTextureFetchWorker::DECODE_IMAGE_UPDATE, LLTextureFetchWorker::WAIT_ON_WRITE };
+
 // static
 volatile bool LLTextureFetch::svMetricsDataBreak(true);	// Start with a data break
 
@@ -919,6 +931,7 @@ LLTextureFetchWorker::LLTextureFetchWorker(LLTextureFetch* fetcher,
 	  mLoadedDiscard(-1),
 	  mDecodedDiscard(-1),
 	  mCacheReadTime(0.f),
+	  mCacheWriteTime(0.f),
 	  mDecodeTime(0.f),
       mFetchTime(0.f),
 	  mCacheReadHandle(LLTextureCache::nullHandle()),
@@ -927,6 +940,7 @@ LLTextureFetchWorker::LLTextureFetchWorker(LLTextureFetch* fetcher,
 	  mRequestedOffset(0),
 	  mDesiredSize(TEXTURE_CACHE_ENTRY_SIZE),
 	  mFileSize(0),
+	  mSkippedStatesTime(0),
 	  mCachedSize(0),
 	  mLoaded(FALSE),
 	  mSentRequest(UNSENT),
@@ -1192,6 +1206,13 @@ bool LLTextureFetchWorker::doWork(S32 param)
 
 	if (mState == INIT)
 	{		
+		mStateTimer.reset();
+		mFetchTimer.reset();
+		for(auto i : LOGGED_STATES) 
+		{
+			mStateTimersMap[i] = 0;
+		}
+		mSkippedStatesTime = 0;
 		mRawImage = NULL ;
 		mRequestedDiscard = -1;
 		mLoadedDiscard = -1;
@@ -1249,9 +1270,10 @@ bool LLTextureFetchWorker::doWork(S32 param)
 				++mCacheReadCount;
 				std::string filename = mUrl.substr(7, std::string::npos);
 				CacheReadResponder* responder = new CacheReadResponder(mFetcher, mID, mFormattedImage);
+				mCacheReadTimer.reset();  
 				mCacheReadHandle = mFetcher->mTextureCache->readFromCache(filename, mID, cache_priority,
 																		  offset, size, responder);
-                mCacheReadTimer.reset();                
+              
 			}
 			else if ((mUrl.empty() || mFTType==FTT_SERVER_BAKE) && mFetcher->canLoadFromCache())
 			{
@@ -1259,9 +1281,9 @@ bool LLTextureFetchWorker::doWork(S32 param)
 
 				++mCacheReadCount;
 				CacheReadResponder* responder = new CacheReadResponder(mFetcher, mID, mFormattedImage);
-				mCacheReadHandle = mFetcher->mTextureCache->readFromCache(mID, cache_priority,
-																		  offset, size, responder);
 				mCacheReadTimer.reset();
+				mCacheReadHandle = mFetcher->mTextureCache->readFromCache(mID, cache_priority,
+																		  offset, size, responder);;
 			}
 			else if(!mUrl.empty() && mCanUseHTTP)
 			{
@@ -1283,6 +1305,7 @@ bool LLTextureFetchWorker::doWork(S32 param)
 				mCacheReadHandle = LLTextureCache::nullHandle();
 				setState(CACHE_POST);
                 add(LLTextureFetch::sCacheHit, 1.0);
+				mCacheReadTime = mCacheReadTimer.getElapsedTimeF32();
 				// fall through
 			}
 			else
@@ -1896,7 +1919,7 @@ bool LLTextureFetchWorker::doWork(S32 param)
 			LL_DEBUGS(LOG_TXT) << mID << " DECODE_IMAGE abort: mLoadedDiscard < 0" << LL_ENDL;
 			return true;
 		}
-
+		mDecodeTimer.reset();
 		mRawImage = NULL;
 		mAuxImage = NULL;
 		llassert_always(mFormattedImage.notNull());
@@ -1990,6 +2013,7 @@ bool LLTextureFetchWorker::doWork(S32 param)
         // be protected by work mutex and won't be safe to use here nor in cache worker.
         // So make sure users of getRequestFinished() does not attempt to modify image while
         // fetcher is working
+		mCacheWriteTimer.reset();
 		mCacheWriteHandle = mFetcher->mTextureCache->writeToCache(mID, cache_priority,
 																  mFormattedImage->getData(), datasize,
 																  mFileSize, mRawImage, mDecodedDiscard, responder);
@@ -2000,6 +2024,7 @@ bool LLTextureFetchWorker::doWork(S32 param)
 	{
 		if (writeToCacheComplete())
 		{
+			mCacheWriteTime = mCacheWriteTimer.getElapsedTimeF32();
 			setState(DONE);
 			// fall through
 		}
@@ -2508,7 +2533,6 @@ void LLTextureFetchWorker::callbackDecoded(bool success, LLImageRaw* raw, LLImag
 	mDecoded = TRUE;
 // 	LL_INFOS(LOG_TXT) << mID << " : DECODE COMPLETE " << LL_ENDL;
 	setPriority(LLWorkerThread::PRIORITY_HIGH | mWorkPriority);
-	mCacheReadTime = mCacheReadTimer.getElapsedTimeF32();
 }																		// -Mw
 
 //////////////////////////////////////////////////////////////////////////////
@@ -2633,6 +2657,17 @@ LLTextureFetch::LLTextureFetch(LLTextureCache* cache, LLImageDecodeThread* image
 		}
 		mOriginFetchSource = mFetchSource;
 	}
+
+	// If that test log has ben requested but not yet created, create it
+	if (LLMetricPerformanceTesterBasic::isMetricLogRequested(sTesterName) && !LLMetricPerformanceTesterBasic::getTester(sTesterName))
+	{
+		sTesterp = new LLTextureFetchTester() ;
+		if (!sTesterp->isValid())
+		{
+			delete sTesterp;
+			sTesterp = NULL;
+		}
+	}
 }
 
 LLTextureFetch::~LLTextureFetch()
@@ -2974,20 +3009,51 @@ bool LLTextureFetch::getRequestFinished(const LLUUID& id, S32& discard_level,
 		}
 		else if (worker->checkWork())
 		{
+			F32 decode_time;
+			F32 fetch_time;
+			F32 cache_read_time;
+			F32 cache_write_time;
+			S32 file_size;
+			std::map<S32, F32> logged_state_timers;
+			F32 skipped_states_time;
 			worker->lockWorkMutex();									// +Mw
 			last_http_get_status = worker->mGetStatus;
 			discard_level = worker->mDecodedDiscard;
 			raw = worker->mRawImage;
 			aux = worker->mAuxImage;
-			sample(sTexDecodeLatency, worker->mDecodeTime);
-            sample(sTexFetchLatency, worker->mFetchTime);
-            sample(sCacheReadLatency, worker->mCacheReadTime);
+
+			decode_time = worker->mDecodeTime;
+			fetch_time = worker->mFetchTime;
+			cache_read_time = worker->mCacheReadTime;
+			cache_write_time = worker->mCacheWriteTime;
+			file_size = worker->mFileSize;
             worker->mCacheReadTimer.reset();
             worker->mDecodeTimer.reset();
+			worker->mCacheWriteTimer.reset();
             worker->mFetchTimer.reset();
+			logged_state_timers = worker->mStateTimersMap;
+			skipped_states_time = worker->mSkippedStatesTime;
+			worker->mStateTimer.reset();
 			res = true;
 			LL_DEBUGS(LOG_TXT) << id << ": Request Finished. State: " << worker->mState << " Discard: " << discard_level << LL_ENDL;
 			worker->unlockWorkMutex();									// -Mw
+			
+			sample(sTexDecodeLatency, decode_time);
+			sample(sTexFetchLatency, fetch_time);
+			sample(sCacheReadLatency, cache_read_time);
+			sample(sCacheWriteLatency, cache_write_time);
+			
+			static LLCachedControl<F32> min_time_to_log(gSavedSettings, "TextureFetchMinTimeToLog", 2.f);
+			if (fetch_time > min_time_to_log)
+			{
+				//LL_INFOS() << "fetch_time: " << fetch_time << " cache_read_time: " << cache_read_time << " decode_time: " << decode_time << " cache_write_time: " << cache_write_time << LL_ENDL;
+
+				LLTextureFetchTester* tester = (LLTextureFetchTester*)LLMetricPerformanceTesterBasic::getTester(sTesterName);
+				if (tester)
+				{
+					tester->updateStats(logged_state_timers, fetch_time, skipped_states_time, file_size) ;
+				}
+			}
 		}
 		else
 		{
@@ -3472,6 +3538,21 @@ void LLTextureFetchWorker::setState(e_state new_state)
 
 //		LL_INFOS(LOG_TXT) << "id: " << mID << " FTType: " << mFTType << " disc: " << mDesiredDiscard << " sz: " << mDesiredSize << " state: " << e_state_name[mState] << " => " << e_state_name[new_state] << LL_ENDL;
 	}
+	
+	F32 d_time = mStateTimer.getElapsedTimeF32();
+	if (d_time >= 0.0001F)
+	{
+		if (LOGGED_STATES.count(mState))
+		{
+			mStateTimersMap[mState] = d_time;
+		}
+		else
+		{
+			mSkippedStatesTime += d_time;
+		}
+	}
+	
+	mStateTimer.reset();
 	mState = new_state;
 }
 
@@ -3687,7 +3768,7 @@ void LLTextureFetch::dump()
 		LLTextureFetchWorker* worker = (LLTextureFetchWorker*)wreq->getWorkerClass();
 		LL_INFOS(LOG_TXT) << " ID: " << worker->mID
 						  << " PRI: " << llformat("0x%08x",wreq->getPriority())
-						  << " STATE: " << worker->sStateDescs[worker->mState]
+						  << " STATE: " << sStateDescs[worker->mState]
 						  << LL_ENDL;
 	}
 
@@ -5129,4 +5210,40 @@ void LLTextureFetchDebugger::callbackHTTP(FetchEntry & fetch, LLCore::HttpRespon
 //End LLTextureFetchDebugger
 ///////////////////////////////////////////////////////////////////////////////////////////
 
+LLTextureFetchTester::LLTextureFetchTester() : LLMetricPerformanceTesterBasic(sTesterName) 
+{
+	mTextureFetchTime = 0;
+	mSkippedStatesTime = 0;
+	mFileSize = 0;
+}
+
+LLTextureFetchTester::~LLTextureFetchTester()
+{
+	outputTestResults();
+	LLTextureFetch::sTesterp = NULL;
+}
+
+//virtual 
+void LLTextureFetchTester::outputTestRecord(LLSD *sd) 
+{	
+	std::string currentLabel = getCurrentLabelName();
+
+	(*sd)[currentLabel]["Texture Fetch Time"]	= (LLSD::Real)mTextureFetchTime;
+	(*sd)[currentLabel]["File Size"]			= (LLSD::Integer)mFileSize;
+	(*sd)[currentLabel]["Skipped States Time"]	= (LLSD::String)llformat("%.6f", mSkippedStatesTime);
+
+	for(auto i : LOGGED_STATES) 
+	{
+		(*sd)[currentLabel][sStateDescs[i]] = mStateTimersMap[i];
+	}
+}
+
+void LLTextureFetchTester::updateStats(const std::map<S32, F32> state_timers, const F32 fetch_time, const F32 skipped_states_time, const S32 file_size)
+{
+	mTextureFetchTime = fetch_time;
+	mStateTimersMap = state_timers;
+	mFileSize = file_size;
+	mSkippedStatesTime = skipped_states_time;
+	outputTestResults();
+}