Fix/Finish VoCache extras

The extras cache was never fully implemented and thus grows forever.
This coupled with the server side "bug" that sends innumerable blank overrides leads users to collect 100MB+ SLEC files which in turn cause significant pauses post TP.

1 files changed, 159 insertions, 42 deletions

diff --git a/indra/newview/llvocache.cpp b/indra/newview/llvocache.cpp
index dd5b9f9fd5..e0b7a5929a 100644
--- a/indra/newview/llvocache.cpp
+++ b/indra/newview/llvocache.cpp
@@ -33,7 +33,7 @@
 #include "llviewerregion.h"
 #include "llagentcamera.h"
 #include "llsdserialize.h"
-
+#include "llworld.h" // For LLWorld::getInstance()
 //static variables
 U32 LLVOCacheEntry::sMinFrameRange = 0;
 F32 LLVOCacheEntry::sNearRadius = 1.0f;
@@ -55,6 +55,10 @@ BOOL check_write(LLAPRFile* apr_file, void* src, S32 n_bytes)
 	return apr_file->write(src, n_bytes) == n_bytes ;
 }
 
+// Material Override Cache needs a version label, so we can upgrade this later.
+const std::string LLGLTFOverrideCacheEntry::VERSION_LABEL = {"GLTFCacheVer"};
+const int LLGLTFOverrideCacheEntry::VERSION = 1;
+
 bool LLGLTFOverrideCacheEntry::fromLLSD(const LLSD& data)
 {
     LL_PROFILE_ZONE_SCOPED_CATEGORY_NETWORK;
@@ -235,6 +239,8 @@ LLVOCacheEntry::LLVOCacheEntry(LLAPRFile* apr_file)
 		}
 		else
 		{
+			// Improve logging around vocache
+			LL_WARNS() << "Error loading cache entry for " << mLocalID << ", size " << size << " aborting!" << LL_ENDL;
 			delete[] mBuffer ;
 			mBuffer = NULL ;
 		}
@@ -1261,6 +1267,10 @@ void LLVOCache::removeEntry(HeaderEntryInfo* entry)
 	{
 		return;
 	}
+	// Bit more tracking of cache creation/destruction.
+	std::string filename;
+	getObjectCacheFilename(entry->mHandle, filename);
+	LL_INFOS() << "Removing entry for region with filename" << filename << LL_ENDL;
 
 	header_entry_queue_t::iterator iter = mHeaderEntryQueue.find(entry);
 	if(iter != mHeaderEntryQueue.end())
@@ -1331,6 +1341,10 @@ void LLVOCache::removeFromCache(HeaderEntryInfo* entry)
 	std::string filename;
 	getObjectCacheFilename(entry->mHandle, filename);
 	LLAPRFile::remove(filename, mLocalAPRFilePoolp);
+	// Note: `removeFromCache` should take responsibility for cleaning up all cache artefacts specfic to the handle/entry.
+	// as such this now includes the generic extras
+	removeGenericExtrasForHandle(entry->mHandle);
+
 	entry->mTime = INVALID_TIME ;
 	updateEntry(entry) ; //update the head file.
 }
@@ -1478,12 +1492,14 @@ BOOL LLVOCache::updateEntry(const HeaderEntryInfo* entry)
 	return check_write(&apr_file, (void*)entry, sizeof(HeaderEntryInfo)) ;
 }
 
-void LLVOCache::readFromCache(U64 handle, const LLUUID& id, LLVOCacheEntry::vocache_entry_map_t& cache_entry_map) 
+// we now return bool to trigger dirty cache
+// this in turn forces a rewrite after a partial read due to corruption.
+bool LLVOCache::readFromCache(U64 handle, const LLUUID& id, LLVOCacheEntry::vocache_entry_map_t& cache_entry_map) 
 {
 	if(!mEnabled)
 	{
 		LL_WARNS() << "Not reading cache for handle " << handle << "): Cache is currently disabled." << LL_ENDL;
-		return ;
+		return true; // no problem we're just read only
 	}
 	llassert_always(mInitialized);
 
@@ -1491,10 +1507,11 @@ void LLVOCache::readFromCache(U64 handle, const LLUUID& id, LLVOCacheEntry::voca
 	if(iter == mHandleEntryMap.end()) //no cache
 	{
 		LL_WARNS() << "No handle map entry for " << handle << LL_ENDL;
-		return ;
+		return false; // arguably no a problem, but we'll mark this as dirty anyway.
 	}
 
 	bool success = true ;
+	S32 num_entries = 0 ; // lifted out of inner loop. 
 	{
 		std::string filename;
 		LLUUID cache_id;
@@ -1513,7 +1530,6 @@ void LLVOCache::readFromCache(U64 handle, const LLUUID& id, LLVOCacheEntry::voca
 
 			if(success)
 			{
-				S32 num_entries;  // if removal was enabled during write num_entries might be wrong
 				success = check_read(&apr_file, &num_entries, sizeof(S32)) ;
 	
 				if(success)
@@ -1542,11 +1558,17 @@ void LLVOCache::readFromCache(U64 handle, const LLUUID& id, LLVOCacheEntry::voca
 		}
 	}
 
-	return ;
+	LL_DEBUGS("GLTF", "VOCache") << "Read " << cache_entry_map.size() << " entries from object cache " << filename << ", expected " << num_entries << ", success=" << (success?"True":"False") << LL_ENDL;
+	return success;
 }
 
-void LLVOCache::readGenericExtrasFromCache(U64 handle, const LLUUID& id, LLVOCacheEntry::vocache_gltf_overrides_map_t& cache_extras_entry_map)
+// We now pass in the cache entry map, so that we can remove entries from extras that are no longer in the primary cache.
+void LLVOCache::readGenericExtrasFromCache(U64 handle, const LLUUID& id, LLVOCacheEntry::vocache_gltf_overrides_map_t& cache_extras_entry_map, const LLVOCacheEntry::vocache_entry_map_t& cache_entry_map)
 {
+    int loaded= 0;
+    int discarded = 0;
+    // get ViewerRegion pointer from handle
+    LLViewerRegion* pRegion = LLWorld::getInstance()->getRegionFromHandle(handle);
     if(!mEnabled)
     {
         LL_WARNS() << "Not reading cache for handle " << handle << "): Cache is currently disabled." << LL_ENDL;
@@ -1568,19 +1590,35 @@ void LLVOCache::readGenericExtrasFromCache(U64 handle, const LLUUID& id, LLVOCac
     std::getline(in, line);
     if(!in.good()) {
         LL_WARNS() << "Failed reading extras cache for handle " << handle << LL_ENDL;
+        in.close();
+        removeGenericExtrasForHandle(handle);
         return;
     }
+    // file formats need versions, let's add one. legacy cache files will be considered version 0
+    // This will make it easier to upgrade/revise later.
+    int versionNumber=0;
+    if (line.compare(0, LLGLTFOverrideCacheEntry::VERSION_LABEL.length(), LLGLTFOverrideCacheEntry::VERSION_LABEL) == 0) 
+    {
+        std::string versionStr = line.substr(LLGLTFOverrideCacheEntry::VERSION_LABEL.length()+1); // skip the version label and ':'
+        versionNumber = std::stol(versionStr);
+        std::getline(in, line); // read the next line for the region UUID check
+    }
 
     if(!LLUUID::validate(line))
     {
         LL_WARNS() << "Failed reading extras cache for handle" << handle << ". invalid uuid line: '" << line << "'" << LL_ENDL;
+        in.close();
+        removeGenericExtrasForHandle(handle);
         return;
     }
 
     LLUUID cache_id(line);
     if(cache_id != id)
     {
-        LL_INFOS() << "Cache ID doesn't match for this region, discarding" << LL_ENDL;
+        // if the cache id doesn't match the expected region we should just kill the file.
+        LL_WARNS() << "Cache ID doesn't match for this region, deleting it" << LL_ENDL;
+        in.close();
+        removeGenericExtrasForHandle(handle);
         return;
     }
 
@@ -1588,6 +1626,8 @@ void LLVOCache::readGenericExtrasFromCache(U64 handle, const LLUUID& id, LLVOCac
     std::getline(in, line);
     if(!in.good()) {
         LL_WARNS() << "Failed reading extras cache for handle " << handle << LL_ENDL;
+        in.close();
+        removeGenericExtrasForHandle(handle);
         return;
     }
     try {
@@ -1596,10 +1636,12 @@ void LLVOCache::readGenericExtrasFromCache(U64 handle, const LLUUID& id, LLVOCac
     catch(std::logic_error&)  // either invalid_argument or out_of_range
     {
         LL_WARNS() << "Failed reading extras cache for handle " << handle << ". unreadable num_entries" << LL_ENDL;
+        in.close();
+        removeGenericExtrasForHandle(handle);
         return;
     }
 
-    LL_DEBUGS("GLTF") << "Beginning reading extras cache for handle " << handle << ", " << num_entries << " entries" << LL_ENDL;
+    LL_DEBUGS("GLTF") << "Beginning reading extras cache for handle " << handle << " from " << getObjectCacheExtrasFilename(handle) << LL_ENDL;
 
     LLSD entry_llsd;
     for (U32 i = 0; i < num_entries && !in.eof(); i++)
@@ -1608,46 +1650,63 @@ void LLVOCache::readGenericExtrasFromCache(U64 handle, const LLUUID& id, LLVOCac
         bool success = LLSDSerialize::deserialize(entry_llsd, in, max_size);
         // check bool(in) this time since eof is not a failure condition here
         if(!success || !in) {
-            LL_WARNS() << "Failed reading extras cache for handle " << handle << ", entry number " << i << LL_ENDL;
-            return;
-        }
+            LL_WARNS() << "Failed reading extras cache for handle " << handle << ", entry number " << i << " cache patrtial load only." << LL_ENDL;
+            in.close();
+            removeGenericExtrasForHandle(handle);
+            break;
 
         LLGLTFOverrideCacheEntry entry;
         entry.fromLLSD(entry_llsd);
         U32 local_id = entry_llsd["local_id"].asInteger();
-        cache_extras_entry_map[local_id] = entry;
+        // only add entries that exist in the primary cache
+        // this is a self-healing test that avoids us polluting the cache with entries that are no longer valid based on the main cache.
+        if(cache_entry_map.find(local_id)!= cache_entry_map.end())
+        {
+            // attempt to backfill a null objectId, though these shouldn't be in the persisted cache really
+            if(entry.mObjectId.isNull() && pRegion)
+            {
+                gObjectList.getUUIDFromLocal( entry.mObjectId, local_id, pRegion->getHost().getAddress(), pRegion->getHost().getPort() );
+            }
+            cache_extras_entry_map[local_id] = entry;
+            loaded++;
+        }
+        else
+        {
+            discarded++;
+        }
     }
-
-    LL_DEBUGS("GLTF") << "Completed reading extras cache for handle " << handle << ", " << num_entries << " entries" << LL_ENDL;
+    LL_DEBUGS("GLTF") << "Completed reading extras cache for handle " << handle << ", " << loaded << " loaded, " << discarded << " discarded" << LL_ENDL;
 }
 
 void LLVOCache::purgeEntries(U32 size)
 {
+	LL_DEBUGS("VOCache","GLTF") << "Purging " << size << " entries from cache" << LL_ENDL;
 	while(mHeaderEntryQueue.size() > size)
 	{
 		header_entry_queue_t::iterator iter = mHeaderEntryQueue.begin() ;
-		HeaderEntryInfo* entry = *iter ;			
-		mHandleEntryMap.erase(entry->mHandle);
+		HeaderEntryInfo* entry = *iter ;
+		mHandleEntryMap.erase(entry->mHandle) ;
 		mHeaderEntryQueue.erase(iter) ;
-		removeFromCache(entry) ;
+		removeFromCache(entry) ; // This now handles removing extras cache where appropriate.
 		delete entry;
-        // TODO also delete extras
 	}
 	mNumEntries = mHandleEntryMap.size() ;
 }
 
 void LLVOCache::writeToCache(U64 handle, const LLUUID& id, const LLVOCacheEntry::vocache_entry_map_t& cache_entry_map, BOOL dirty_cache, bool removal_enabled) 
 {
+	std::string filename;
+	getObjectCacheFilename(handle, filename);
 	if(!mEnabled)
 	{
-		LL_WARNS() << "Not writing cache for handle " << handle << "): Cache is currently disabled." << LL_ENDL;
+		LL_WARNS() << "Not writing cache for " << filename << " (handle:" << handle << "): Cache is currently disabled." << LL_ENDL;
 		return ;
 	}
 	llassert_always(mInitialized);
 
 	if(mReadOnly)
 	{
-		LL_WARNS() << "Not writing cache for handle " << handle << "): Cache is currently in read-only mode." << LL_ENDL;
+		LL_WARNS() << "Not writing cache for " << filename << " (handle:" << handle << "): Cache is currently in read-only mode." << LL_ENDL;
 		return ;
 	}	
 
@@ -1682,13 +1741,13 @@ void LLVOCache::writeToCache(U64 handle, const LLUUID& id, const LLVOCacheEntry:
 	//update cache header
 	if(!updateEntry(entry))
 	{
-		LL_WARNS() << "Failed to update cache header index " << entry->mIndex << ". handle = " << handle << LL_ENDL;
+		LL_WARNS() << "Failed to update cache header index " << entry->mIndex << ". " << filename << " handle = " << handle << LL_ENDL;
 		return ; //update failed.
 	}
 
 	if(!dirty_cache)
 	{
-		LL_WARNS() << "Skipping write to cache for handle " << handle << ": cache not dirty" << LL_ENDL;
+		LL_WARNS() << "Skipping write to cache for " << filename << " (handle:" << handle << "): cache not dirty" << LL_ENDL;
 		return ; //nothing changed, no need to update.
 	}
 
@@ -1724,6 +1783,7 @@ void LLVOCache::writeToCache(U64 handle, const LLUUID& id, const LLVOCacheEntry:
                         }
                         else
                         {
+                            LL_WARNS() << "Failed to write cache entry to buffer for " << filename << ", entry number " << iter->second->getLocalID() << LL_ENDL;
                             success = false;
                             break;
                         }
@@ -1735,6 +1795,7 @@ void LLVOCache::writeToCache(U64 handle, const LLUUID& id, const LLVOCacheEntry:
                             size_in_buffer = 0;
                             if (!success)
                             {
+                                LL_WARNS() << "Failed to write cache to disk " << filename << LL_ENDL;
                                 break;
                             }
                         }
@@ -1745,8 +1806,13 @@ void LLVOCache::writeToCache(U64 handle, const LLUUID& id, const LLVOCacheEntry:
                 {
                     // final write
                     success = check_write(&apr_file, (void*)data_buffer, size_in_buffer);
+                    if(!success)
+                    {
+                        LL_WARNS() << "Failed to write cache entry to disk " << filename << LL_ENDL;
+                    }
                     size_in_buffer = 0;
                 }
+                LL_DEBUGS("VOCache") << "Wrote " << num_entries << " entries to the primary VOCache file " << filename << ". success = " << (success ? "True":"False") << LL_ENDL;
             }
 		}
 	}
@@ -1759,6 +1825,17 @@ void LLVOCache::writeToCache(U64 handle, const LLUUID& id, const LLVOCacheEntry:
 	return ;
 }
 
+void LLVOCache::removeGenericExtrasForHandle(U64 handle)
+{
+    if(mReadOnly)
+    {
+        LL_WARNS() << "Not removing cache for handle " << handle << ": Cache is currently in read-only mode." << LL_ENDL;
+        return ;
+    }
+    LL_WARNS("GLTF", "VOCache") << "Removing generic extras for handle " << handle << "Filename: " << getObjectCacheExtrasFilename(handle) << LL_ENDL;
+    LLFile::remove(getObjectCacheExtrasFilename(handle));
+}
+
 void LLVOCache::writeGenericExtrasToCache(U64 handle, const LLUUID& id, const LLVOCacheEntry::vocache_gltf_overrides_map_t& cache_extras_entry_map, BOOL dirty_cache, bool removal_enabled)
 {
     if(!mEnabled)
@@ -1774,46 +1851,86 @@ void LLVOCache::writeGenericExtrasToCache(U64 handle, const LLUUID& id, const LL
         return;
     }
 
-    std::string filename(getObjectCacheExtrasFilename(handle));
+    // <FS:Beq> FIRE-33808 - Material Override Cache causes long delays
+    std::string filename = getObjectCacheExtrasFilename(handle);
+    // </FS:Beq>
     llofstream out(filename, std::ios::out | std::ios::binary);
     if(!out.good())
     {
         LL_WARNS() << "Failed writing extras cache for handle " << handle << LL_ENDL;
+        removeGenericExtrasForHandle(handle);
         return;
-        // TODO - clean up broken cache file
     }
+    // It is good practice to version file formats so let's add one.
+    // legacy versions will be treated as version 0.
+    out << LLGLTFOverrideCacheEntry::VERSION_LABEL << ":" << LLGLTFOverrideCacheEntry::VERSION << '\n';
 
     out << id << '\n';
     if(!out.good())
     {
         LL_WARNS() << "Failed writing extras cache for handle " << handle << LL_ENDL;
+        removeGenericExtrasForHandle(handle); 
         return;
-        // TODO - clean up broken cache file
     }
-
-    U32 num_entries = cache_extras_entry_map.size();
-    out << num_entries << '\n';
+	// Because we don't write out all the entries we need to record a placeholder and rewrite this later
+    auto num_entries_placeholder = out.tellp();
+    out << std::setw(10) << std::setfill('0') << 0 << '\n';
     if(!out.good())
     {
         LL_WARNS() << "Failed writing extras cache for handle " << handle << LL_ENDL;
+        removeGenericExtrasForHandle(handle); 
         return;
-        // TODO - clean up broken cache file
     }
 
-    for (auto const & entry : cache_extras_entry_map)
+    // get ViewerRegion pointer from handle
+    LLViewerRegion* pRegion = LLWorld::getInstance()->getRegionFromHandle(handle);
+
+    U32 num_entries = 0;
+    U32 inmem_entries = 0;
+    U32 skipped = 0;
+    inmem_entries = cache_extras_entry_map.size();
+    for (auto [local_id, entry] : cache_extras_entry_map)
     {
-        S32 local_id = entry.first;
-        LLSD entry_llsd = entry.second.toLLSD();
-        entry_llsd["local_id"] = local_id;
-        LLSDSerialize::serialize(entry_llsd, out, LLSDSerialize::LLSD_XML);
-        out << '\n';
-        if(!out.good())
+        // Only write out GLTFOverrides that we can actually apply again on import.
+        // worst case we have an extra cache miss.
+        // Note: A null mObjectId is valid when in memory as we might have a data race between GLTF of the object itself.
+        // This remains a valid state to persist as it is consistent with the localid checks on import with the main cache.
+		// the mObjectId will be updated if/when the local object is updated from the gObject list (due to full update)
+        if(entry.mObjectId.isNull() && pRegion)
         {
-            LL_WARNS() << "Failed writing extras cache for handle " << handle << LL_ENDL;
-            return;
-            // TODO - clean up broken cache file
+            gObjectList.getUUIDFromLocal( entry.mObjectId, local_id, pRegion->getHost().getAddress(), pRegion->getHost().getPort() );
         }
-    }
 
-    LL_DEBUGS("GLTF") << "Completed writing extras cache for handle " << handle << ", " << num_entries << " entries" << LL_ENDL;
+        if( entry.mSides.size() > 0 &&
+            entry.mSides.size() == entry.mGLTFMaterial.size()
+          )
+        {
+            LLSD entry_llsd = entry.toLLSD();
+            entry_llsd["local_id"] = (S32)local_id;
+            LLSDSerialize::serialize(entry_llsd, out, LLSDSerialize::LLSD_XML);
+            out << '\n';
+            if(!out.good())
+            {
+                // We're not in a good place when this happens so we might as well nuke the file.
+                LL_WARNS() << "Failed writing extras cache for handle " << handle << ". Corrupted cache file " << filename << " removed." << LL_ENDL;
+                removeGenericExtrasForHandle(handle);
+                return;
+            }
+            num_entries++;
+        }
+        else
+        {
+            skipped++;
+        }
+    }
+    // Rewrite the placeholder
+    out.seekp(num_entries_placeholder);
+    out << std::setw(10) << std::setfill('0') << num_entries << '\n';
+    if(!out.good())
+    {
+        LL_WARNS() << "Failed writing extras cache for handle " << handle << LL_ENDL;
+        removeGenericExtrasForHandle(handle);
+        return;
+    }
+    LL_DEBUGS("GLTF") << "Completed writing extras cache for handle " << handle << ", " << num_entries << " entries. Total in RAM: " << inmem_entries << " skipped (no persist): " << skipped << LL_ENDL;
 }