livie
/
phoenix-firestorm
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

DN-202: Make avatar name caching more aggressive and error handling more uniform 

Add logging (mostly at DEBUG level)
meow-7.2.2
Oz Linden 2011-01-16 21:41:08 -05:00
parent c5d8624ba4
commit e106678422
3 changed files with 159 additions and 103 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

258
indra/llmessage/llavatarnamecache.cpp
View File

@ -38,6 +38,7 @@
#include <map>
#include <set>
#include <unistd.h>
namespace LLAvatarNameCache
{
@ -81,8 +82,11 @@ namespace LLAvatarNameCache
// only need per-frame timing resolution
LLFrameTimer sRequestTimer;
// Periodically clean out expired entries from the cache
//LLFrameTimer sEraseExpiredTimer;
/// Maximum time an unrefreshed cache entry is allowed
const F64 MAX_UNREFRESHED_TIME = 20.0 * 60.0;
/// Time when unrefreshed cached names were checked last
static F64 sLastExpireCheck;
//-----------------------------------------------------------------------
// Internal methods
@ -99,8 +103,9 @@ namespace LLAvatarNameCache
// Legacy name system callback
void legacyNameCallback(const LLUUID& agent_id,
const std::string& full_name,
bool is_group);
const std::string& full_name,
bool is_group
);
void requestNamesViaLegacy();
@ -117,7 +122,7 @@ namespace LLAvatarNameCache
bool isRequestPending(const LLUUID& agent_id);
// Erase expired names from cache
void eraseExpired();
void eraseUnrefreshed();
bool expirationFromCacheControl(LLSD headers, F64 *expires);
}
@ -187,6 +192,7 @@ public:
{
// Pull expiration out of headers if available
F64 expires = LLAvatarNameCache::nameExpirationFromHeaders(mHeaders);
F64 now = LLFrameTimer::getTotalSeconds();
LLSD agents = content["agents"];
LLSD::array_const_iterator it = agents.beginArray();
@ -207,84 +213,91 @@ public:
av_name.mDisplayName = av_name.mUsername;
}
LL_DEBUGS("AvNameCache") << "LLAvatarNameResponder::result for " << agent_id << " "
<< "user '" << av_name.mUsername << "' "
<< "display '" << av_name.mDisplayName << "' "
<< "expires in " << expires - now << " seconds"
<< LL_ENDL;
// cache it and fire signals
LLAvatarNameCache::processName(agent_id, av_name, true);
}
// Same logic as error response case
LLSD unresolved_agents = content["bad_ids"];
if (unresolved_agents.size() > 0)
S32 num_unresolved = unresolved_agents.size();
if (num_unresolved > 0)
{
const std::string DUMMY_NAME("\?\?\?");
LLAvatarName av_name;
av_name.mUsername = DUMMY_NAME;
av_name.mDisplayName = DUMMY_NAME;
av_name.mIsDisplayNameDefault = false;
av_name.mIsTemporaryName = true;
av_name.mExpires = expires;
LL_WARNS("AvNameCache") << "LLAvatarNameResponder::result " << num_unresolved << " unresolved ids; "
<< "expires in " << expires - now << " seconds"
<< LL_ENDL;
it = unresolved_agents.beginArray();
for ( ; it != unresolved_agents.endArray(); ++it)
{
const LLUUID& agent_id = *it;
// cache it and fire signals
LLAvatarNameCache::processName(agent_id, av_name, true);
LL_WARNS("AvNameCache") << "LLAvatarNameResponder::result "
<< "failed id " << agent_id
<< LL_ENDL;
LLAvatarNameCache::handleAgentError(agent_id);
}
}
}
LL_DEBUGS("AvNameCache") << "LLAvatarNameResponder::result "
<< LLAvatarNameCache::sCache.size() << " cached names"
<< LL_ENDL;
}
/*virtual*/ void error(U32 status, const std::string& reason)
{
// If there's an error, it might be caused by PeopleApi,
// or when loading textures on startup and using a very slow
// network, this query may time out. Fallback to the legacy
// cache.
// network, this query may time out.
// What we should do depends on whether or not we have a cached name
LL_WARNS("AvNameCache") << "LLAvatarNameResponder::error " << status << " " << reason
<< LL_ENDL;
llwarns << "LLAvatarNameResponder error " << status << " " << reason << llendl;
// Add dummy records for all agent IDs in this request
// Add dummy records for any agent IDs in this request that we do not have cached already
std::vector<LLUUID>::const_iterator it = mAgentIDs.begin();
for ( ; it != mAgentIDs.end(); ++it)
{
const LLUUID& agent_id = *it;
gCacheName->get(agent_id, false, // legacy compatibility
boost::bind(&LLAvatarNameCache::legacyNameCallback,
_1, _2, _3));
LLAvatarNameCache::handleAgentError(agent_id);
}
}
// Return time to retry a request that generated an error, based on
// error type and headers. Return value is seconds-since-epoch.
F64 errorRetryTimestamp(S32 status)
{
F64 now = LLFrameTimer::getTotalSeconds();
// Retry-After takes priority
LLSD retry_after = mHeaders["retry-after"];
if (retry_after.isDefined())
{
// We only support the delta-seconds type
S32 delta_seconds = retry_after.asInteger();
if (delta_seconds > 0)
{
// ...valid delta-seconds
return now + F64(delta_seconds);
}
}
// If no Retry-After, look for Cache-Control max-age
F64 expires = 0.0;
if (LLAvatarNameCache::expirationFromCacheControl(mHeaders, &expires))
{
return expires;
}
// No information in header, make a guess
const F64 DEFAULT_DELAY = 120.0; // 2 mintues
return now + DEFAULT_DELAY;
}
};
// Provide some fallback for agents that return errors
void LLAvatarNameCache::handleAgentError(const LLUUID& agent_id)
{
std::map<LLUUID,LLAvatarName>::iterator existing = sCache.find(agent_id);
if (existing == sCache.end())
{
// there is no existing cache entry, so make a temporary name from legacy
LL_WARNS("AvNameCache") << "LLAvatarNameCache get legacy for agent "
<< agent_id << LL_ENDL;
gCacheName->get(agent_id, false, // legacy compatibility
boost::bind(&LLAvatarNameCache::legacyNameCallback,
_1, _2, _3));
}
else
{
// we have a chached (but probably expired) entry - since that would have
// been returned by the get method, there is no need to signal anyone
// Clear this agent from the pending list
LLAvatarNameCache::sPendingQueue.erase(agent_id);
const LLAvatarName& av_name = existing->second;
LL_DEBUGS("AvNameCache") << "LLAvatarNameCache use cache for agent "
<< agent_id
<< "user '" << av_name.mUsername << "' "
<< "display '" << av_name.mDisplayName << "' "
<< "expires in " << av_name.mExpires - LLFrameTimer::getTotalSeconds() << " seconds"
<< LL_ENDL;
}
}
void LLAvatarNameCache::processName(const LLUUID& agent_id,
const LLAvatarName& av_name,
bool add_to_cache)
@ -326,6 +339,7 @@ void LLAvatarNameCache::requestNamesViaCapability()
std::vector<LLUUID> agent_ids;
agent_ids.reserve(128);
U32 ids = 0;
ask_queue_t::const_iterator it = sAskQueue.begin();
for ( ; it != sAskQueue.end(); ++it)
{
@ -336,11 +350,13 @@ void LLAvatarNameCache::requestNamesViaCapability()
// ...starting new request
url += sNameLookupURL;
url += "?ids=";
ids = 1;
}
else
{
// ...continuing existing request
url += "&ids=";
ids++;
}
url += agent_id.asString();
agent_ids.push_back(agent_id);
@ -350,8 +366,10 @@ void LLAvatarNameCache::requestNamesViaCapability()
if (url.size() > NAME_URL_SEND_THRESHOLD)
{
//llinfos << "requestNames " << url << llendl;
LLHTTPClient::get(url, new LLAvatarNameResponder(agent_ids));//, LLSD(), 10.0f);
LL_DEBUGS("AvNameCache") << "LLAvatarNameCache::requestNamesViaCapability first "
<< ids << " ids"
<< LL_ENDL;
LLHTTPClient::get(url, new LLAvatarNameResponder(agent_ids));
url.clear();
agent_ids.clear();
}
@ -359,8 +377,10 @@ void LLAvatarNameCache::requestNamesViaCapability()
if (!url.empty())
{
//llinfos << "requestNames " << url << llendl;
LLHTTPClient::get(url, new LLAvatarNameResponder(agent_ids));//, LLSD(), 10.0f);
LL_DEBUGS("AvNameCache") << "LLAvatarNameCache::requestNamesViaCapability all "
<< ids << " ids"
<< LL_ENDL;
LLHTTPClient::get(url, new LLAvatarNameResponder(agent_ids));
url.clear();
agent_ids.clear();
}
@ -376,6 +396,11 @@ void LLAvatarNameCache::legacyNameCallback(const LLUUID& agent_id,
// Construct a dummy record for this name. By convention, SLID is blank
// Never expires, but not written to disk, so lasts until end of session.
LLAvatarName av_name;
LL_DEBUGS("AvNameCache") << "LLAvatarNameCache::legacyNameCallback "
<< "agent " << agent_id << " "
<< "full name '" << full_name << "'"
<< ( is_group ? " [group]" : "" )
<< LL_ENDL;
buildLegacyName(full_name, &av_name);
// Don't add to cache, the data already exists in the legacy name system
@ -397,6 +422,8 @@ void LLAvatarNameCache::requestNamesViaLegacy()
// invoked below. This should never happen in practice.
sPendingQueue[agent_id] = now;
LL_DEBUGS("AvNameCache") << "LLAvatarNameCache::requestNamesViaLegacy agent " << agent_id << LL_ENDL;
gCacheName->get(agent_id, false, // legacy compatibility
boost::bind(&LLAvatarNameCache::legacyNameCallback,
_1, _2, _3));
@ -435,21 +462,24 @@ void LLAvatarNameCache::importFile(std::istream& istr)
av_name.fromLLSD( it->second );
sCache[agent_id] = av_name;
}
// entries may have expired since we last ran the viewer, just
// clean them out now
eraseExpired();
llinfos << "loaded " << sCache.size() << llendl;
// Some entries may have expired since the cache was stored,
// but next time they are read that will be checked.
// Expired entries are filtered out when the cache is stored,
// or in eraseUnrefreshed
LL_INFOS("AvNameCache") << "loaded " << sCache.size() << LL_ENDL;
}
void LLAvatarNameCache::exportFile(std::ostream& ostr)
{
LLSD agents;
F64 now = LLFrameTimer::getTotalSeconds();
cache_t::const_iterator it = sCache.begin();
for ( ; it != sCache.end(); ++it)
{
const LLUUID& agent_id = it->first;
const LLAvatarName& av_name = it->second;
if (!av_name.mIsTemporaryName)
// Do not write temporary or expired entries to the stored cache
if (!av_name.mIsTemporaryName && av_name.mExpires >= now)
{
// key must be a string
agents[agent_id.asString()] = av_name.asLLSD();
@ -484,56 +514,63 @@ void LLAvatarNameCache::idle()
// return;
//}
// Must be large relative to above
// No longer deleting expired entries, just re-requesting in the get
// this way first synchronous get call on an expired entry won't return
// legacy name. LF
if (sAskQueue.empty())
if (!sAskQueue.empty())
{
return;
if (useDisplayNames())
{
requestNamesViaCapability();
}
else
{
// ...fall back to legacy name cache system
requestNamesViaLegacy();
}
}
if (useDisplayNames())
{
requestNamesViaCapability();
}
else
{
// ...fall back to legacy name cache system
requestNamesViaLegacy();
}
// erase anything that has not been refreshed for more than MAX_UNREFRESHED_TIME
eraseUnrefreshed();
}
bool LLAvatarNameCache::isRequestPending(const LLUUID& agent_id)
{
bool isPending = false;
const F64 PENDING_TIMEOUT_SECS = 5.0 * 60.0;
F64 now = LLFrameTimer::getTotalSeconds();
F64 expire_time = now - PENDING_TIMEOUT_SECS;
pending_queue_t::const_iterator it = sPendingQueue.find(agent_id);
if (it != sPendingQueue.end())
{
bool request_expired = (it->second < expire_time);
return !request_expired;
// in the list of requests in flight, retry if too old
F64 expire_time = LLFrameTimer::getTotalSeconds() - PENDING_TIMEOUT_SECS;
isPending = (it->second > expire_time);
}
return false;
return isPending;
}
void LLAvatarNameCache::eraseExpired()
void LLAvatarNameCache::eraseUnrefreshed()
{
F64 now = LLFrameTimer::getTotalSeconds();
cache_t::iterator it = sCache.begin();
while (it != sCache.end())
{
cache_t::iterator cur = it;
++it;
const LLAvatarName& av_name = cur->second;
if (av_name.mExpires < now)
{
sCache.erase(cur);
}
F64 max_unrefreshed = now - MAX_UNREFRESHED_TIME;
if (!sLastExpireCheck || sLastExpireCheck < max_unrefreshed)
{
sLastExpireCheck = now;
cache_t::iterator it = sCache.begin();
while (it != sCache.end())
{
cache_t::iterator cur = it;
++it;
const LLAvatarName& av_name = cur->second;
if (av_name.mExpires < max_unrefreshed)
{
const LLUUID& agent_id = it->first;
LL_DEBUGS("AvNameCache") << agent_id
<< " user '" << av_name.mUsername << "' "
<< "expired " << now - av_name.mExpires << " secs ago"
<< LL_ENDL;
sCache.erase(cur);
}
}
LL_INFOS("AvNameCache") << sCache.size() << " cached avatar names" << LL_ENDL;
}
}
@ -545,7 +582,10 @@ void LLAvatarNameCache::buildLegacyName(const std::string& full_name,
av_name->mDisplayName = full_name;
av_name->mIsDisplayNameDefault = true;
av_name->mIsTemporaryName = true;
av_name->mExpires = F64_MAX;
av_name->mExpires = F64_MAX; // not used because these are not cached
LL_DEBUGS("AvNameCache") << "LLAvatarNameCache::buildLegacyName "
<< full_name
<< LL_ENDL;
}
// fills in av_name if it has it in the cache, even if expired (can check expiry time)
@ -568,6 +608,9 @@ bool LLAvatarNameCache::get(const LLUUID& agent_id, LLAvatarName *av_name)
{
if (!isRequestPending(agent_id))
{
LL_DEBUGS("AvNameCache") << "LLAvatarNameCache::get "
<< "refresh agent " << agent_id
<< LL_ENDL;
sAskQueue.insert(agent_id);
}
}
@ -589,6 +632,9 @@ bool LLAvatarNameCache::get(const LLUUID& agent_id, LLAvatarName *av_name)
if (!isRequestPending(agent_id))
{
LL_DEBUGS("AvNameCache") << "LLAvatarNameCache::get "
<< "queue request for agent " << agent_id
<< LL_ENDL;
sAskQueue.insert(agent_id);
}
@ -621,7 +667,6 @@ void LLAvatarNameCache::get(const LLUUID& agent_id, callback_slot_t slot)
{
// ...name already exists in cache, fire callback now
fireSignal(agent_id, slot, av_name);
return;
}
}
@ -717,6 +762,9 @@ F64 LLAvatarNameCache::nameExpirationFromHeaders(LLSD headers)
bool LLAvatarNameCache::expirationFromCacheControl(LLSD headers, F64 *expires)
{
bool fromCacheControl = false;
F64 now = LLFrameTimer::getTotalSeconds();
// Allow the header to override the default
LLSD cache_control_header = headers["cache-control"];
if (cache_control_header.isDefined())
@ -725,12 +773,16 @@ bool LLAvatarNameCache::expirationFromCacheControl(LLSD headers, F64 *expires)
std::string cache_control = cache_control_header.asString();
if (max_age_from_cache_control(cache_control, &max_age))
{
F64 now = LLFrameTimer::getTotalSeconds();
*expires = now + (F64)max_age;
return true;
fromCacheControl = true;
}
}
return false;
LL_DEBUGS("AvNameCache")
<< ( fromCacheControl ? "expires based on cache control " : "default expiration " )
<< "in " << *expires - now << " seconds"
<< LL_ENDL;
return fromCacheControl;
}

3
indra/llmessage/llavatarnamecache.h
View File

@ -82,6 +82,9 @@ namespace LLAvatarNameCache
void erase(const LLUUID& agent_id);
/// Provide some fallback for agents that return errors
void handleAgentError(const LLUUID& agent_id);
// Force a re-fetch of the most recent data, but keep the current
// data in cache
void fetch(const LLUUID& agent_id);

1
indra/newview/llappviewer.cpp
View File

@ -3734,6 +3734,7 @@ void LLAppViewer::loadNameCache()
// display names cache
std::string filename =
gDirUtilp->getExpandedFilename(LL_PATH_CACHE, "avatar_name_cache.xml");
LL_INFOS("AvNameCache") << filename << LL_ENDL;
llifstream name_cache_stream(filename);
if(name_cache_stream.is_open())
{