diff options
| -rwxr-xr-x | indra/newview/llagent.cpp | 6 | ||||
| -rwxr-xr-x | indra/newview/llagentwearables.cpp | 2 | ||||
| -rw-r--r-- | indra/newview/llagentwearablesfetch.cpp | 4 | ||||
| -rwxr-xr-x | indra/newview/llappearancemgr.cpp | 2 | ||||
| -rwxr-xr-x[-rw-r--r--] | indra/newview/llappviewer.cpp | 6 | ||||
| -rwxr-xr-x | indra/newview/llviewerstats.cpp | 38 | ||||
| -rwxr-xr-x | indra/newview/llviewerstats.h | 4 | ||||
| -rwxr-xr-x | indra/newview/llvoavatar.cpp | 101 | ||||
| -rwxr-xr-x | indra/newview/llvoavatar.h | 12 | ||||
| -rwxr-xr-x | indra/newview/llvoavatarself.cpp | 35 | ||||
| -rwxr-xr-x | indra/newview/llvoavatarself.h | 7 |
11 files changed, 164 insertions, 53 deletions
diff --git a/indra/newview/llagent.cpp b/indra/newview/llagent.cpp index abd83485af..c86b75791d 100755 --- a/indra/newview/llagent.cpp +++ b/indra/newview/llagent.cpp @@ -4338,12 +4338,10 @@ void LLAgent::sendAgentSetAppearance() if (!gAgentWearables.changeInProgress()) { // Change is fully resolved, can close some open phases. - gAgentAvatarp->getPhases().stopPhase("process_initial_wearables_update"); - gAgentAvatarp->getPhases().stopPhase("wear_inventory_category"); + gAgentAvatarp->stopPhase("process_initial_wearables_update"); + gAgentAvatarp->stopPhase("wear_inventory_category"); } - gAgentAvatarp->sendAppearanceChangeMetrics(); - if (!isAgentAvatarValid() || (getRegion() && getRegion()->getCentralBakeVersion())) return; // At this point we have a complete appearance to send and are in a non-baking region. diff --git a/indra/newview/llagentwearables.cpp b/indra/newview/llagentwearables.cpp index 70f4de8db2..0c79ac0ba3 100755 --- a/indra/newview/llagentwearables.cpp +++ b/indra/newview/llagentwearables.cpp @@ -797,7 +797,7 @@ void LLAgentWearables::processAgentInitialWearablesUpdate(LLMessageSystem* mesgs if (isAgentAvatarValid()) { //gAgentAvatarp->clearPhases(); // reset phase timers for outfit loading. - gAgentAvatarp->getPhases().startPhase("process_initial_wearables_update"); + gAgentAvatarp->startPhase("process_initial_wearables_update"); gAgentAvatarp->outputRezTiming("Received initial wearables update"); } diff --git a/indra/newview/llagentwearablesfetch.cpp b/indra/newview/llagentwearablesfetch.cpp index 2d622b380a..6f1658d1cc 100644 --- a/indra/newview/llagentwearablesfetch.cpp +++ b/indra/newview/llagentwearablesfetch.cpp @@ -80,7 +80,7 @@ LLInitialWearablesFetch::LLInitialWearablesFetch(const LLUUID& cof_id) : { if (isAgentAvatarValid()) { - gAgentAvatarp->getPhases().startPhase("initial_wearables_fetch"); + gAgentAvatarp->startPhase("initial_wearables_fetch"); gAgentAvatarp->outputRezTiming("Initial wearables fetch started"); } } @@ -99,7 +99,7 @@ void LLInitialWearablesFetch::done() doOnIdleOneTime(boost::bind(&LLInitialWearablesFetch::processContents,this)); if (isAgentAvatarValid()) { - gAgentAvatarp->getPhases().stopPhase("initial_wearables_fetch"); + gAgentAvatarp->stopPhase("initial_wearables_fetch"); gAgentAvatarp->outputRezTiming("Initial wearables fetch done"); } } diff --git a/indra/newview/llappearancemgr.cpp b/indra/newview/llappearancemgr.cpp index f1ba4ad453..1a6d49c7a2 100755 --- a/indra/newview/llappearancemgr.cpp +++ b/indra/newview/llappearancemgr.cpp @@ -2006,8 +2006,6 @@ void LLAppearanceMgr::updateAppearanceFromCOF(bool update_base_outfit_ordering) llwarns << "Called updateAppearanceFromCOF inside updateAppearanceFromCOF, skipping" << llendl; return; } - - LLVOAvatar::ScopedPhaseSetter(gAgentAvatarp,"update_appearance_from_cof"); BoolSetter setIsInUpdateAppearanceFromCOF(mIsInUpdateAppearanceFromCOF); diff --git a/indra/newview/llappviewer.cpp b/indra/newview/llappviewer.cpp index 03b11939a9..2ee325a09e 100644..100755 --- a/indra/newview/llappviewer.cpp +++ b/indra/newview/llappviewer.cpp @@ -3612,6 +3612,12 @@ void LLAppViewer::requestQuit() // Try to send metrics back to the grid metricsSend(!gDisconnected); + + // Try to send last batch of avatar rez metrics. + if (!gDisconnected && isAgentAvatarValid()) + { + gAgentAvatarp->updateAvatarRezMetrics(true); // force a last packet to be sent. + } LLHUDEffectSpiral *effectp = (LLHUDEffectSpiral*)LLHUDManager::getInstance()->createViewerEffect(LLHUDObject::LL_HUD_EFFECT_POINT, TRUE); effectp->setPositionGlobal(gAgent.getPositionGlobal()); diff --git a/indra/newview/llviewerstats.cpp b/indra/newview/llviewerstats.cpp index bccd4c1a60..28c6b59391 100755 --- a/indra/newview/llviewerstats.cpp +++ b/indra/newview/llviewerstats.cpp @@ -733,6 +733,10 @@ void send_stats() LLHTTPClient::post(url, body, new ViewerStatsResponder()); } +LLViewerStats::PhaseMap::PhaseMap() +{ +} + LLTimer& LLViewerStats::PhaseMap::getPhaseTimer(const std::string& phase_name) { phase_map_t::iterator iter = mPhaseMap.find(phase_name); @@ -761,32 +765,26 @@ void LLViewerStats::PhaseMap::stopPhase(const std::string& phase_name) { // Going from started to paused state - record stats. recordPhaseStat(phase_name,iter->second.getElapsedTimeF32()); + iter->second.stop(); } - lldebugs << "stopPhase " << phase_name << llendl; - iter->second.stop(); - } - else - { - lldebugs << "stopPhase " << phase_name << " is not started, no-op" << llendl; } } -void LLViewerStats::PhaseMap::stopAllPhases() +bool LLViewerStats::PhaseMap::getPhaseValues(const std::string& phase_name, F32& elapsed, bool& completed) { - for (phase_map_t::iterator iter = mPhaseMap.begin(); - iter != mPhaseMap.end(); ++iter) + phase_map_t::iterator iter = mPhaseMap.find(phase_name); + if (iter != mPhaseMap.end()) { - const std::string& phase_name = iter->first; - if (iter->second.getStarted()) - { - // Going from started to paused state - record stats. - recordPhaseStat(phase_name,iter->second.getElapsedTimeF32()); - } - lldebugs << "stopPhase (all) " << phase_name << llendl; - iter->second.stop(); + elapsed = iter->second.getElapsedTimeF32(); + completed = !iter->second.getStarted(); + return true; + } + else + { + return false; } } - + void LLViewerStats::PhaseMap::clearPhases() { lldebugs << "clearPhases" << llendl; @@ -810,10 +808,6 @@ LLSD LLViewerStats::PhaseMap::dumpPhases() //static LLViewerStats::phase_stats_t LLViewerStats::PhaseMap::sStats; -LLViewerStats::PhaseMap::PhaseMap() -{ -} - // static LLViewerStats::StatsAccumulator& LLViewerStats::PhaseMap::getPhaseStats(const std::string& phase_name) { diff --git a/indra/newview/llviewerstats.h b/indra/newview/llviewerstats.h index bb11e8c5be..084f5ae7d1 100755 --- a/indra/newview/llviewerstats.h +++ b/indra/newview/llviewerstats.h @@ -289,13 +289,15 @@ public: public: PhaseMap(); LLTimer& getPhaseTimer(const std::string& phase_name); + bool getPhaseValues(const std::string& phase_name, F32& elapsed, bool& completed); void startPhase(const std::string& phase_name); void stopPhase(const std::string& phase_name); - void stopAllPhases(); void clearPhases(); LLSD dumpPhases(); static StatsAccumulator& getPhaseStats(const std::string& phase_name); static void recordPhaseStat(const std::string& phase_name, F32 value); + phase_map_t::iterator begin() { return mPhaseMap.begin(); } + phase_map_t::iterator end() { return mPhaseMap.end(); } }; private: diff --git a/indra/newview/llvoavatar.cpp b/indra/newview/llvoavatar.cpp index 483bc25b33..f7e1944660 100755 --- a/indra/newview/llvoavatar.cpp +++ b/indra/newview/llvoavatar.cpp @@ -5887,30 +5887,123 @@ void LLVOAvatar::updateRezzedStatusTimers() if (is_cloud && !was_cloud) { // start cloud timer. - getPhases().startPhase("cloud"); + startPhase("cloud"); } else if (was_cloud && !is_cloud) { // stop cloud timer, which will capture stats. - getPhases().stopPhase("cloud"); + stopPhase("cloud"); } // Non-cloud-or-gray to cloud-or-gray if (is_cloud_or_gray && !was_cloud_or_gray) { // start cloud-or-gray timer. - getPhases().startPhase("cloud-or-gray"); + startPhase("cloud-or-gray"); } else if (was_cloud_or_gray && !is_cloud_or_gray) { // stop cloud-or-gray timer, which will capture stats. - getPhases().stopPhase("cloud-or-gray"); + stopPhase("cloud-or-gray"); } mLastRezzedStatus = rez_status; } } +void LLVOAvatar::clearPhases() +{ + getPhases().clearPhases(); +} + +void LLVOAvatar::startPhase(const std::string& phase_name) +{ + getPhases().startPhase(phase_name); +} + +void LLVOAvatar::logPendingPhases() +{ + for (LLViewerStats::phase_map_t::iterator it = getPhases().begin(); + it != getPhases().end(); + ++it) + { + const std::string& phase_name = it->first; + F32 elapsed; + bool completed; + if (getPhases().getPhaseValues(phase_name, elapsed, completed)) + { + if (!completed) + { + logMetricsTimerRecord(phase_name, elapsed, completed); + } + else + { + llwarns << "ignoring " << phase_name << llendl; + } + } + } +} + +//static +void LLVOAvatar::logPendingPhasesAllAvatars() +{ + for (std::vector<LLCharacter*>::iterator iter = LLCharacter::sInstances.begin(); + iter != LLCharacter::sInstances.end(); ++iter) + { + LLVOAvatar* inst = (LLVOAvatar*) *iter; + if( inst->isDead() ) + { + continue; + } + inst->logPendingPhases(); + } +} + +void LLVOAvatar::logMetricsTimerRecord(const std::string& phase_name, F32 elapsed, bool completed) +{ + LLSD record; + record["timer_name"] = phase_name; + record["agent_id"] = gAgent.getID(); + record["elapsed"] = elapsed; + record["completed"] = completed; + U32 grid_x(0), grid_y(0); + if (getRegion()) + { + record["cbv"] = getRegion()->getCentralBakeVersion(); + grid_from_region_handle(getRegion()->getHandle(), &grid_x, &grid_y); + } + record["grid_x"] = LLSD::Integer(grid_x); + record["grid_y"] = LLSD::Integer(grid_y); + record["is_using_server_bake"] = isUsingServerBakes(); + record["is_self"] = isSelf(); + + LL_DEBUGS("Avatar") << "record\n" << ll_pretty_print_sd(record) << llendl; +} + +void LLVOAvatar::stopPhase(const std::string& phase_name) +{ + F32 elapsed; + bool completed; + if (getPhases().getPhaseValues(phase_name, elapsed, completed)) + { + if (!completed) + { + getPhases().stopPhase(phase_name); + completed = true; + + } + else + { + llwarns << "stop when stopped already for " << phase_name << llendl; + } + logMetricsTimerRecord(phase_name, elapsed, completed); + } + else + { + llwarns << "stop when not started for " << phase_name << llendl; + } +} + // call periodically to keep isFullyLoaded up to date. // returns true if the value has changed. BOOL LLVOAvatar::updateIsFullyLoaded() diff --git a/indra/newview/llvoavatar.h b/indra/newview/llvoavatar.h index c14f18d00e..8babcc3ef3 100755 --- a/indra/newview/llvoavatar.h +++ b/indra/newview/llvoavatar.h @@ -292,12 +292,16 @@ public: S32 mLastRezzedStatus; - LLViewerStats::PhaseMap& getPhases() - { - return mPhases; - } + + void startPhase(const std::string& phase_name); + void stopPhase(const std::string& phase_name); + void clearPhases(); + void logPendingPhases(); + static void logPendingPhasesAllAvatars(); + void logMetricsTimerRecord(const std::string& phase_name, F32 elapsed, bool completed); protected: + LLViewerStats::PhaseMap& getPhases() { return mPhases; } BOOL updateIsFullyLoaded(); BOOL processFullyLoadedChange(bool loading); void updateRuthTimer(bool loading); diff --git a/indra/newview/llvoavatarself.cpp b/indra/newview/llvoavatarself.cpp index a1c7cf97ff..3ae4f9bc71 100755 --- a/indra/newview/llvoavatarself.cpp +++ b/indra/newview/llvoavatarself.cpp @@ -81,7 +81,7 @@ void selfStartPhase(const std::string& phase_name) { if (isAgentAvatarValid()) { - gAgentAvatarp->getPhases().startPhase(phase_name); + gAgentAvatarp->startPhase(phase_name); } } @@ -89,7 +89,7 @@ void selfStopPhase(const std::string& phase_name) { if (isAgentAvatarValid()) { - gAgentAvatarp->getPhases().stopPhase(phase_name); + gAgentAvatarp->stopPhase(phase_name); } } @@ -97,19 +97,11 @@ void selfClearPhases() { if (isAgentAvatarValid()) { - gAgentAvatarp->getPhases().clearPhases(); + gAgentAvatarp->clearPhases(); gAgentAvatarp->mLastRezzedStatus = -1; } } -void selfStopAllPhases() -{ - if (isAgentAvatarValid()) - { - gAgentAvatarp->getPhases().stopAllPhases(); - } -} - using namespace LLAvatarAppearanceDefines; /********************************************************************************* @@ -222,6 +214,7 @@ void LLVOAvatarSelf::initInstance() } //doPeriodically(output_self_av_texture_diagnostics, 30.0); + doPeriodically(boost::bind(&LLVOAvatarSelf::updateAvatarRezMetrics, this, false), 5.0); } // virtual @@ -2238,6 +2231,22 @@ private: volatile bool & mReportingStarted; }; +bool LLVOAvatarSelf::updateAvatarRezMetrics(bool force_send) +{ + F32 send_period = 30.0; + + if (force_send || mTimeSinceLastRezMessage.getElapsedTimeF32() > send_period) + { + // Stats for completed phases have been getting logged as they + // complete. This will give us stats for any timers that + // haven't finished as of the metric's being sent. + LLVOAvatar::logPendingPhasesAllAvatars(); + sendAppearanceChangeMetrics(); + } + + return false; +} + void LLVOAvatarSelf::sendAppearanceChangeMetrics() { // gAgentAvatarp->stopAllPhases(); @@ -2251,7 +2260,9 @@ void LLVOAvatarSelf::sendAppearanceChangeMetrics() msg["sequence"] = report_sequence; msg["initial"] = !reporting_started; msg["break"] = false; - + msg["duration"] = mTimeSinceLastRezMessage.getElapsedTimeF32(); + mTimeSinceLastRezMessage.reset(); + // Update sequence number if (S32_MAX == ++report_sequence) report_sequence = 0; diff --git a/indra/newview/llvoavatarself.h b/indra/newview/llvoavatarself.h index 74888e470d..857c482f93 100755 --- a/indra/newview/llvoavatarself.h +++ b/indra/newview/llvoavatarself.h @@ -379,6 +379,10 @@ public: LLUUID mAvatarID; LLAvatarAppearanceDefines::ETextureIndex mIndex; }; + + LLTimer mTimeSinceLastRezMessage; + bool updateAvatarRezMetrics(bool force_send); + void debugWearablesLoaded() { mDebugTimeWearablesLoaded = mDebugSelfLoadTimer.getElapsedTimeF32(); } void debugAvatarVisible() { mDebugTimeAvatarVisible = mDebugSelfLoadTimer.getElapsedTimeF32(); } void outputRezDiagnostics() const; @@ -416,7 +420,8 @@ BOOL isAgentAvatarValid(); void selfStartPhase(const std::string& phase_name); void selfStopPhase(const std::string& phase_name); -void selfStopAllPhases(); void selfClearPhases(); +void update_avatar_rez_metrics(bool force_send); + #endif // LL_VO_AVATARSELF_H |