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: [PATCH] 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/llappearancemgr.cpp | 2 +
indra/newview/lltexlayer.cpp | 1 +
indra/newview/llvoavatar.cpp | 4 +-
indra/newview/llvoavatarself.cpp | 70 ++++++++++++++++++++++++++-----
indra/newview/llvoavatarself.h | 23 ++++++++++
indra/newview/llwearable.cpp | 3 ++
6 files changed, 91 insertions(+), 12 deletions(-)
diff --git a/indra/newview/llappearancemgr.cpp b/indra/newview/llappearancemgr.cpp
index be840cc3488..4aef72ab0b0 100644
--- a/indra/newview/llappearancemgr.cpp
+++ b/indra/newview/llappearancemgr.cpp
@@ -524,6 +524,7 @@ bool LLWearableHoldingPattern::pollMissingWearables()
if (done)
{
+ gAgentAvatarp->wearablesLoaded();
clearCOFLinksForMissingWearables();
onAllComplete();
}
@@ -1649,6 +1650,7 @@ void LLAppearanceMgr::autopopulateOutfits()
// Handler for anything that's deferred until avatar de-clouds.
void LLAppearanceMgr::onFirstFullyVisible()
{
+ gAgentAvatarp->avatarVisible();
autopopulateOutfits();
}
diff --git a/indra/newview/lltexlayer.cpp b/indra/newview/lltexlayer.cpp
index 82fa6723422..337627cc795 100644
--- a/indra/newview/lltexlayer.cpp
+++ b/indra/newview/lltexlayer.cpp
@@ -237,6 +237,7 @@ BOOL LLTexLayerSetBuffer::render()
{
if (mTexLayerSet->isVisible())
{
+ mTexLayerSet->getAvatar()->bakedTextureUpload(mTexLayerSet->getBakedTexIndex(), FALSE); // FALSE for start of upload, TRUE for finish.
readBackAndUpload();
}
else
diff --git a/indra/newview/llvoavatar.cpp b/indra/newview/llvoavatar.cpp
index 2ec8ced543d..c64f7b5a3ea 100644
--- a/indra/newview/llvoavatar.cpp
+++ b/indra/newview/llvoavatar.cpp
@@ -5869,14 +5869,14 @@ void LLVOAvatar::updateRuthTimer(bool loading)
const F32 LOADING_TIMEOUT = 120.f;
if (mRuthTimer.getElapsedTimeF32() > LOADING_TIMEOUT)
{
- /*
+
llinfos << "Ruth Timer timeout: Missing texture data for '" << getFullname() << "' "
<< "( Params loaded : " << !visualParamWeightsAreDefault() << " ) "
<< "( Lower : " << isTextureDefined(TEX_LOWER_BAKED) << " ) "
<< "( Upper : " << isTextureDefined(TEX_UPPER_BAKED) << " ) "
<< "( Head : " << isTextureDefined(TEX_HEAD_BAKED) << " )."
<< llendl;
- */
+
LLAvatarPropertiesProcessor::getInstance()->sendAvatarTexturesRequest(getID());
mRuthTimer.reset();
}
diff --git a/indra/newview/llvoavatarself.cpp b/indra/newview/llvoavatarself.cpp
index dec2e7efdf9..739c021311b 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;
+ }
}
}
diff --git a/indra/newview/llvoavatarself.h b/indra/newview/llvoavatarself.h
index 460291a9293..03856b3a3b3 100644
--- a/indra/newview/llvoavatarself.h
+++ b/indra/newview/llvoavatarself.h
@@ -124,6 +124,11 @@ class LLVOAvatarSelf :
//--------------------------------------------------------------------
public:
/*virtual*/ BOOL getIsCloud();
+ void bakedTextureUpload(LLVOAvatarDefines::EBakedTextureIndex index, BOOL finished);
+ static void onTimingLocalTexLoaded(BOOL success, LLViewerFetchedTexture *src_vi, LLImageRaw* src, LLImageRaw* aux_src, S32 discard_level, BOOL final, void* userdata);
+ void wearablesLoaded() { mTimeWearablesLoaded = mSelfLoadTimer.getElapsedTimeF32(); }
+ void avatarVisible() { mTimeAvatarVisible = mSelfLoadTimer.getElapsedTimeF32(); }
+
private:
//--------------------------------------------------------------------
@@ -132,6 +137,14 @@ class LLVOAvatarSelf :
U64 mLastRegionHandle;
LLFrameTimer mRegionCrossingTimer;
S32 mRegionCrossingCount;
+ LLFrameTimer mSelfLoadTimer;
+ F32 mTimeWearablesLoaded;
+ F32 mTimeAvatarVisible;
+ F32 mTextureLoadTimes[LLVOAvatarDefines::TEX_NUM_INDICES][MAX_DISCARD_LEVEL+1]; // stores load time for each texture,
+ // at each discard level
+ F32 mBakedTextureTimes[LLVOAvatarDefines::BAKED_NUM_INDICES][2]; // stores time to start upload and finish upload of each baked texture
+
+ void timingLocalTexLoaded(BOOL success, LLViewerFetchedTexture *src_vi, LLImageRaw* src, LLImageRaw* aux_src, S32 discard_level, BOOL final, void* userdata);
/** State
** **
@@ -332,6 +345,16 @@ class LLVOAvatarSelf :
** **
*******************************************************************************/
+struct LLAvatarTexData
+{
+ LLAvatarTexData(const LLUUID& id, LLVOAvatarDefines::ETextureIndex index) :
+ mAvatarID(id),
+ mIndex(index)
+ {}
+ LLUUID mAvatarID;
+ LLVOAvatarDefines::ETextureIndex mIndex;
+};
+
};
extern LLVOAvatarSelf *gAgentAvatarp;
diff --git a/indra/newview/llwearable.cpp b/indra/newview/llwearable.cpp
index 3ecd1296bd2..28613c8bcf4 100644
--- a/indra/newview/llwearable.cpp
+++ b/indra/newview/llwearable.cpp
@@ -442,6 +442,9 @@ BOOL LLWearable::importFile( LLFILE* file )
delete mSavedTEMap[te];
}
+ image->setLoadedCallback(LLVOAvatarSelf::onTimingLocalTexLoaded,0,TRUE,FALSE, new LLVOAvatarSelf::LLAvatarTexData(id, (LLVOAvatarDefines::ETextureIndex)te));
+
+
LLUUID textureid(text_buffer);
mTEMap[te] = new LLLocalTextureObject(image, textureid);
mSavedTEMap[te] = new LLLocalTextureObject(image, textureid);
--
GitLab