From b416dcb73b1f405ebf5260cc588b07fde7ad1604 Mon Sep 17 00:00:00 2001
From: "Nyx (Neal Orman)" <nyx@lindenlab.com>
Date: Tue, 18 May 2010 10:20:44 -0400
Subject: adding verbose logging around your own avatar rez time. Documents
 load times for each component texture at each discard level, as well as baked
 texture upload times, and reports the timing of each texture to the console
 when your avatar sends out its appearance data to the server.

Reviewed by Seraph, will be removed before release.

 -Nyx
---
 indra/newview/llvoavatarself.cpp | 70 ++++++++++++++++++++++++++++++++++------
 1 file changed, 60 insertions(+), 10 deletions(-)

(limited to 'indra/newview/llvoavatarself.cpp')

diff --git a/indra/newview/llvoavatarself.cpp b/indra/newview/llvoavatarself.cpp
index dec2e7efdf..739c021311 100644
--- a/indra/newview/llvoavatarself.cpp
+++ b/indra/newview/llvoavatarself.cpp
@@ -103,15 +103,7 @@ struct LocalTextureData
 //-----------------------------------------------------------------------------
 // Callback data
 //-----------------------------------------------------------------------------
-struct LLAvatarTexData
-{
-	LLAvatarTexData(const LLUUID& id, ETextureIndex index) : 
-		mAvatarID(id), 
-		mIndex(index) 
-	{}
-	LLUUID			mAvatarID;
-	ETextureIndex	mIndex;
-};
+
 
 /**
  **
@@ -156,6 +148,23 @@ void LLVOAvatarSelf::initInstance()
 	// adds attachment points to mScreen among other things
 	LLVOAvatar::initInstance();
 
+	llinfos << "Self avatar object created. Starting timer." << llendl;
+	mSelfLoadTimer.reset();
+	// clear all times to -1 for debugging
+	for (U32 i =0; i < LLVOAvatarDefines::TEX_NUM_INDICES; ++i)
+	{
+		for (U32 j = 0; j <= MAX_DISCARD_LEVEL; ++j)
+		{
+			mTextureLoadTimes[i][j] = -1.0f;
+		}
+	}
+
+	for (U32 i =0; i < LLVOAvatarDefines::BAKED_NUM_INDICES; ++i)
+	{
+		mBakedTextureTimes[i][0] = -1.0f;
+		mBakedTextureTimes[i][1] = -1.0f;
+	}
+
 	status &= buildMenus();
 	if (!status)
 	{
@@ -1117,12 +1126,12 @@ U32 LLVOAvatarSelf::getNumWearables(LLVOAvatarDefines::ETextureIndex i) const
 // virtual
 void LLVOAvatarSelf::localTextureLoaded(BOOL success, LLViewerFetchedTexture *src_vi, LLImageRaw* src_raw, LLImageRaw* aux_src, S32 discard_level, BOOL final, void* userdata)
 {	
-	//llinfos << "onLocalTextureLoaded: " << src_vi->getID() << llendl;
 
 	const LLUUID& src_id = src_vi->getID();
 	LLAvatarTexData *data = (LLAvatarTexData *)userdata;
 	ETextureIndex index = data->mIndex;
 	if (!isIndexLocalTexture(index)) return;
+
 	LLLocalTextureObject *local_tex_obj = getLocalTextureObject(index, 0);
 
 	// fix for EXT-268. Preventing using of NULL pointer
@@ -1748,6 +1757,32 @@ BOOL LLVOAvatarSelf::getIsCloud()
 	return FALSE;
 }
 
+/*static*/
+void LLVOAvatarSelf::onTimingLocalTexLoaded(BOOL success, LLViewerFetchedTexture *src_vi, LLImageRaw* src, LLImageRaw* aux_src, S32 discard_level, BOOL final, void* userdata)
+{
+	gAgentAvatarp->timingLocalTexLoaded(success, src_vi, src, aux_src, discard_level, final, userdata);
+}
+
+void LLVOAvatarSelf::timingLocalTexLoaded(BOOL success, LLViewerFetchedTexture *src_vi, LLImageRaw* src, LLImageRaw* aux_src, S32 discard_level, BOOL final, void* userdata)
+{
+	LLAvatarTexData *data = (LLAvatarTexData *)userdata;
+	ETextureIndex index = data->mIndex;
+
+	if (discard_level >=0 && discard_level <= MAX_DISCARD_LEVEL) // ignore discard level -1, as it means we have no data.
+	{
+		mTextureLoadTimes[(U32)index][(U32)discard_level] = mSelfLoadTimer.getElapsedTimeF32();
+	}
+}
+
+void LLVOAvatarSelf::bakedTextureUpload(EBakedTextureIndex index, BOOL finished)
+{
+	U32 done = 0;
+	if (finished)
+	{
+		done = 1;
+	}
+	mBakedTextureTimes[index][done] = mSelfLoadTimer.getElapsedTimeF32();
+}
 
 const LLUUID& LLVOAvatarSelf::grabLocalTexture(ETextureIndex type, U32 index) const
 {
@@ -1907,6 +1942,7 @@ void LLVOAvatarSelf::setNewBakedTexture( ETextureIndex te, const LLUUID& uuid )
 	const LLVOAvatarDictionary::TextureEntry *texture_dict = LLVOAvatarDictionary::getInstance()->getTexture(te);
 	if (texture_dict->mIsBakedTexture)
 	{
+		bakedTextureUpload(texture_dict->mBakedTextureIndex, TRUE); // FALSE for start of upload, TRUE for finish.
 		llinfos << "New baked texture: " << texture_dict->mName << " UUID: " << uuid <<llendl;
 	}
 	else
@@ -1919,6 +1955,20 @@ void LLVOAvatarSelf::setNewBakedTexture( ETextureIndex te, const LLUUID& uuid )
 	if (!hasPendingBakedUploads())
 	{
 		gAgent.sendAgentSetAppearance();
+		F32 final_time = mSelfLoadTimer.getElapsedTimeF32();
+		llinfos << "time from avatar creation to load wearables: " << mTimeWearablesLoaded << llendl;
+		llinfos << "time from avatar creation to de-cloud: " << mTimeAvatarVisible << llendl;
+		llinfos << "time from avatar creation to de-cloud for others: " << final_time << llendl;
+		llinfos << "load time for each texture: " << llendl;
+		for (U32 i = 0; i < LLVOAvatarDefines::TEX_NUM_INDICES; ++i)
+		{
+			llinfos << "(" << i << "): " << (S32)mTextureLoadTimes[i][0] << "\t" << (S32)mTextureLoadTimes[i][1] << "\t" << (S32)mTextureLoadTimes[i][2] << "\t" << (S32)mTextureLoadTimes[i][3] << "\t" << (S32)mTextureLoadTimes[i][4] << "\t" << (S32)mTextureLoadTimes[i][5] << llendl;
+		}
+		llinfos << "Time points for each upload (start / finish)" << llendl;
+		for (U32 i = 0; i < LLVOAvatarDefines::BAKED_NUM_INDICES; ++i)
+		{
+			llinfos << "(" << i << "): " << (S32)mBakedTextureTimes[i][0] << " / " << (S32)mBakedTextureTimes[i][1] << llendl;
+		}
 	}
 }
 
-- 
cgit v1.2.3