1 files changed, 19 insertions, 16 deletions

diff --git a/indra/llmessage/llavatarnamecache.cpp b/indra/llmessage/llavatarnamecache.cpp
index ef097c70f2..88b88d0454 100755
--- a/indra/llmessage/llavatarnamecache.cpp
+++ b/indra/llmessage/llavatarnamecache.cpp
@@ -428,8 +428,7 @@ void LLAvatarNameCache::legacyNameFetch(const LLUUID& agent_id,
 										const std::string& full_name,
 										bool is_group)
 {
-	LL_DEBUGS("AvNameCache") << "LLAvatarNameCache::legacyNameFetch "
-	                         << "agent " << agent_id << " "
+	LL_DEBUGS("AvNameCache") << "LLAvatarNameCache agent " << agent_id << " "
 							 << "full name '" << full_name << "'"
 	                         << ( is_group ? " [group]" : "" )
 	                         << LL_ENDL;
@@ -458,7 +457,7 @@ 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;
+		LL_DEBUGS("AvNameCache") << "agent " << agent_id << LL_ENDL;
 
 		gCacheName->get(agent_id, false,  // legacy compatibility
 			boost::bind(&LLAvatarNameCache::legacyNameCallback, _1, _2, _3));
@@ -485,12 +484,13 @@ void LLAvatarNameCache::cleanupClass()
     sCache.clear();
 }
 
-void LLAvatarNameCache::importFile(std::istream& istr)
+bool LLAvatarNameCache::importFile(std::istream& istr)
 {
 	LLSD data;
 	if (LLSDParser::PARSE_FAILURE == LLSDSerialize::fromXMLDocument(data, istr))
 	{
-		return;
+        LL_WARNS("AvNameCache") << "avatar name cache data xml parse failed" << LL_ENDL;
+		return false;
 	}
 
 	// by convention LLSD storage is a map
@@ -506,17 +506,19 @@ void LLAvatarNameCache::importFile(std::istream& istr)
 		av_name.fromLLSD( it->second );
 		sCache[agent_id] = av_name;
 	}
-    LL_INFOS("AvNameCache") << "loaded " << sCache.size() << LL_ENDL;
-
+    LL_INFOS("AvNameCache") << "LLAvatarNameCache loaded " << sCache.size() << LL_ENDL;
 	// Some entries may have expired since the cache was stored,
     // but they will be flushed in the first call to eraseUnrefreshed
     // from LLAvatarNameResponder::idle
+
+    return true;
 }
 
 void LLAvatarNameCache::exportFile(std::ostream& ostr)
 {
 	LLSD agents;
 	F64 max_unrefreshed = LLFrameTimer::getTotalSeconds() - MAX_UNREFRESHED_TIME;
+    LL_INFOS("AvNameCache") << "LLAvatarNameCache at exit cache has " << sCache.size() << LL_ENDL;
 	cache_t::const_iterator it = sCache.begin();
 	for ( ; it != sCache.end(); ++it)
 	{
@@ -529,6 +531,7 @@ void LLAvatarNameCache::exportFile(std::ostream& ostr)
 			agents[agent_id.asString()] = av_name.asLLSD();
 		}
 	}
+    LL_INFOS("AvNameCache") << "LLAvatarNameCache returning " << agents.size() << LL_ENDL;
 	LLSD data;
 	data["agents"] = agents;
 	LLSDSerialize::toPrettyXML(data, ostr);
@@ -571,6 +574,7 @@ void LLAvatarNameCache::idle()
         }
         else
         {
+            LL_WARNS_ONCE("AvNameCache") << "LLAvatarNameCache still using legacy api" << LL_ENDL;
             requestNamesViaLegacy();
         }
 	}
@@ -608,24 +612,26 @@ void LLAvatarNameCache::eraseUnrefreshed()
     if (!sLastExpireCheck || sLastExpireCheck < max_unrefreshed)
     {
         sLastExpireCheck = now;
-
+        S32 expired = 0;
         for (cache_t::iterator it = sCache.begin(); it != sCache.end();)
         {
             const LLAvatarName& av_name = it->second;
             if (av_name.mExpires < max_unrefreshed)
             {
-                LL_DEBUGS("AvNameCache") << it->first 
+                LL_DEBUGS("AvNameCacheExpired") << "LLAvatarNameCache " << it->first 
                                          << " user '" << av_name.getAccountName() << "' "
                                          << "expired " << now - av_name.mExpires << " secs ago"
                                          << LL_ENDL;
                 sCache.erase(it++);
+                expired++;
             }
 			else
 			{
 				++it;
 			}
         }
-        LL_INFOS("AvNameCache") << sCache.size() << " cached avatar names" << LL_ENDL;
+        LL_INFOS("AvNameCache") << "LLAvatarNameCache expired " << expired << " cached avatar names, "
+                                << sCache.size() << " remaining" << LL_ENDL;
 	}
 }
 
@@ -646,8 +652,7 @@ bool LLAvatarNameCache::get(const LLUUID& agent_id, LLAvatarName *av_name)
 			{
 				if (!isRequestPending(agent_id))
 				{
-					LL_DEBUGS("AvNameCache") << "LLAvatarNameCache::get "
-											 << "refresh agent " << agent_id
+					LL_DEBUGS("AvNameCache") << "LLAvatarNameCache refresh agent " << agent_id
 											 << LL_ENDL;
 					sAskQueue.insert(agent_id);
 				}
@@ -659,9 +664,7 @@ 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;
+		LL_DEBUGS("AvNameCache") << "LLAvatarNameCache queue request for agent " << agent_id << LL_ENDL;
 		sAskQueue.insert(agent_id);
 	}
 
@@ -834,7 +837,7 @@ bool LLAvatarNameCache::expirationFromCacheControl(const LLSD& headers, F64 *exp
 			fromCacheControl = true;
 		}
 	}
-	LL_DEBUGS("AvNameCache")
+	LL_DEBUGS("AvNameCache") << "LLAvatarNameCache "
 		<< ( fromCacheControl ? "expires based on cache control " : "default expiration " )
 		<< "in " << *expires - now << " seconds"
 		<< LL_ENDL;