From b416dcb73b1f405ebf5260cc588b07fde7ad1604 Mon Sep 17 00:00:00 2001 From: "Nyx (Neal Orman)" 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 < Date: Tue, 18 May 2010 15:15:08 -0400 Subject: AVP-72 FIXED Debug settings for gathering Welcome Island Rez time statistics Fixed memory leak. Prettied up formatting for debug readouts. Added more notifications for rez and cloud time. --- indra/newview/llvoavatarself.cpp | 37 ++++++++++++++++++++++++++++++------- 1 file changed, 30 insertions(+), 7 deletions(-) (limited to 'indra/newview/llvoavatarself.cpp') diff --git a/indra/newview/llvoavatarself.cpp b/indra/newview/llvoavatarself.cpp index 739c021311..e8f42178a1 100644 --- a/indra/newview/llvoavatarself.cpp +++ b/indra/newview/llvoavatarself.cpp @@ -1772,6 +1772,7 @@ void LLVOAvatarSelf::timingLocalTexLoaded(BOOL success, LLViewerFetchedTexture * { mTextureLoadTimes[(U32)index][(U32)discard_level] = mSelfLoadTimer.getElapsedTimeF32(); } + delete data; } void LLVOAvatarSelf::bakedTextureUpload(EBakedTextureIndex index, BOOL finished) @@ -1956,18 +1957,40 @@ void LLVOAvatarSelf::setNewBakedTexture( ETextureIndex te, const LLUUID& uuid ) { 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; + llinfos << "AVATARREZTIME: Myself rez stats:" << llendl; + llinfos << "\t Time from avatar creation to load wearables: " << (S32)mTimeWearablesLoaded << llendl; + llinfos << "\t Time from avatar creation to de-cloud: " << (S32)mTimeAvatarVisible << llendl; + llinfos << "\t Time from avatar creation to de-cloud for others: " << (S32)final_time << llendl; + llinfos << "\t 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; + std::stringstream out; + out << "\t\t (" << i << ") "; + U32 j=0; + for (j=0; j <= MAX_DISCARD_LEVEL; j++) + { + out << "\t"; + S32 load_time = (S32)mTextureLoadTimes[i][j]; + if (load_time == -1) + { + out << "*"; + if (j == 0) + break; + } + else + { + out << load_time; + } + } + + // Don't print out non-existent textures. + if (j != 0) + llinfos << out.str() << llendl; } - llinfos << "Time points for each upload (start / finish)" << llendl; + llinfos << "\t 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; + llinfos << "\t\t (" << i << ") \t" << (S32)mBakedTextureTimes[i][0] << " / " << (S32)mBakedTextureTimes[i][1] << llendl; } } } -- cgit v1.2.3 From dd4c0fa41701a53a11987b3adf837d49119cfbc2 Mon Sep 17 00:00:00 2001 From: Loren Shih Date: Tue, 18 May 2010 16:16:10 -0400 Subject: AVP-72 FIXED Debug settings for gathering Welcome Island Rez time statistics Fix for conditional deletion. --- indra/newview/llvoavatarself.cpp | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) (limited to 'indra/newview/llvoavatarself.cpp') diff --git a/indra/newview/llvoavatarself.cpp b/indra/newview/llvoavatarself.cpp index e8f42178a1..6eaec0e7a1 100644 --- a/indra/newview/llvoavatarself.cpp +++ b/indra/newview/llvoavatarself.cpp @@ -1772,7 +1772,10 @@ void LLVOAvatarSelf::timingLocalTexLoaded(BOOL success, LLViewerFetchedTexture * { mTextureLoadTimes[(U32)index][(U32)discard_level] = mSelfLoadTimer.getElapsedTimeF32(); } - delete data; + if (final) + { + delete data; + } } void LLVOAvatarSelf::bakedTextureUpload(EBakedTextureIndex index, BOOL finished) @@ -1957,7 +1960,7 @@ void LLVOAvatarSelf::setNewBakedTexture( ETextureIndex te, const LLUUID& uuid ) { gAgent.sendAgentSetAppearance(); F32 final_time = mSelfLoadTimer.getElapsedTimeF32(); - llinfos << "AVATARREZTIME: Myself rez stats:" << llendl; + llinfos << "REZTIME: Myself rez stats:" << llendl; llinfos << "\t Time from avatar creation to load wearables: " << (S32)mTimeWearablesLoaded << llendl; llinfos << "\t Time from avatar creation to de-cloud: " << (S32)mTimeAvatarVisible << llendl; llinfos << "\t Time from avatar creation to de-cloud for others: " << (S32)final_time << llendl; -- cgit v1.2.3 From b9a8e7f4282f521fc382a8ac083eb2375183cfa9 Mon Sep 17 00:00:00 2001 From: "Nyx (Neal Orman)" Date: Tue, 18 May 2010 17:44:24 -0400 Subject: crash prevention for viewer debug logging. Will be code reviewed before push, will be removed before release. -Nyx --- indra/newview/llvoavatarself.cpp | 9 +++++++++ 1 file changed, 9 insertions(+) (limited to 'indra/newview/llvoavatarself.cpp') diff --git a/indra/newview/llvoavatarself.cpp b/indra/newview/llvoavatarself.cpp index 739c021311..61cae3b64f 100644 --- a/indra/newview/llvoavatarself.cpp +++ b/indra/newview/llvoavatarself.cpp @@ -1766,7 +1766,16 @@ void LLVOAvatarSelf::onTimingLocalTexLoaded(BOOL success, LLViewerFetchedTexture void LLVOAvatarSelf::timingLocalTexLoaded(BOOL success, LLViewerFetchedTexture *src_vi, LLImageRaw* src, LLImageRaw* aux_src, S32 discard_level, BOOL final, void* userdata) { LLAvatarTexData *data = (LLAvatarTexData *)userdata; + if (!data) + { + return; + } + ETextureIndex index = data->mIndex; + if (index < 0 || index >= TEX_NUM_INDICES) + { + return; + } if (discard_level >=0 && discard_level <= MAX_DISCARD_LEVEL) // ignore discard level -1, as it means we have no data. { -- cgit v1.2.3 From 263877fec111f77d3116913c440e454cba216c61 Mon Sep 17 00:00:00 2001 From: "Nyx (Neal Orman)" Date: Tue, 18 May 2010 18:03:01 -0400 Subject: FIX: crash on texture load callback timer. After reviewing with bao, re-initialize memory to be NULL after delete to ensure that stray callbacks don't try to use it. --- indra/newview/llvoavatarself.cpp | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) (limited to 'indra/newview/llvoavatarself.cpp') diff --git a/indra/newview/llvoavatarself.cpp b/indra/newview/llvoavatarself.cpp index 79b235afae..695ea68ae8 100644 --- a/indra/newview/llvoavatarself.cpp +++ b/indra/newview/llvoavatarself.cpp @@ -1772,7 +1772,8 @@ void LLVOAvatarSelf::timingLocalTexLoaded(BOOL success, LLViewerFetchedTexture * } ETextureIndex index = data->mIndex; - if (index < 0 || index >= TEX_NUM_INDICES) + +if (index < 0 || index >= TEX_NUM_INDICES) { return; } @@ -1784,6 +1785,8 @@ void LLVOAvatarSelf::timingLocalTexLoaded(BOOL success, LLViewerFetchedTexture * if (final) { delete data; + // for debugging, apparently there is a case in which we are keeping old de-allocated structures around in callbacks + *data = NULL; } } -- cgit v1.2.3 From c70be25eca32ff3c8bab9af060b8e5c8cd684344 Mon Sep 17 00:00:00 2001 From: Loren Shih Date: Tue, 18 May 2010 18:28:23 -0400 Subject: Fix for build error (not from my code ;-) ). --- indra/newview/llvoavatarself.cpp | 2 -- 1 file changed, 2 deletions(-) (limited to 'indra/newview/llvoavatarself.cpp') diff --git a/indra/newview/llvoavatarself.cpp b/indra/newview/llvoavatarself.cpp index 695ea68ae8..8bf082ad45 100644 --- a/indra/newview/llvoavatarself.cpp +++ b/indra/newview/llvoavatarself.cpp @@ -1785,8 +1785,6 @@ if (index < 0 || index >= TEX_NUM_INDICES) if (final) { delete data; - // for debugging, apparently there is a case in which we are keeping old de-allocated structures around in callbacks - *data = NULL; } } -- cgit v1.2.3