SL-17329: Do logging of individual files after the disk cache purge finishes so it doesn't affect the time measurement.

The time resolution of the debug log is in seconds, so it's not particularly useful.

Arguably, one could remove this fine logging in favor of Tracy markers. Or have both. Depends on the use case.

1 files changed, 24 insertions, 12 deletions

diff --git a/indra/llfilesystem/lldiskcache.cpp b/indra/llfilesystem/lldiskcache.cpp
index ee43a599f7..74955df50a 100644
--- a/indra/llfilesystem/lldiskcache.cpp
+++ b/indra/llfilesystem/lldiskcache.cpp
@@ -131,28 +131,45 @@ void LLDiskCache::purge()
 
     LL_INFOS() << "Purging cache to a maximum of " << mMaxSizeBytes << " bytes" << LL_ENDL;
 
+    std::vector<bool> file_removed;
+    if (mEnableCacheDebugInfo)
+    {
+        file_removed.reserve(file_info.size());
+    }
     uintmax_t file_size_total = 0;
     for (file_info_t& entry : file_info)
     {
         file_size_total += entry.second.first;
 
+        bool should_remove = file_size_total > mMaxSizeBytes;
+        if (mEnableCacheDebugInfo)
+        {
+            file_removed.push_back(should_remove);
+        }
         std::string action = "";
-        if (file_size_total > mMaxSizeBytes)
+        if (should_remove)
         {
-            action = "DELETE:";
             boost::filesystem::remove(entry.second.second, ec);
             if (ec.failed())
             {
                 LL_WARNS() << "Failed to delete cache file " << entry.second.second << ": " << ec.message() << LL_ENDL;
             }
         }
-        else
-        {
-            action = "  KEEP:";
-        }
+    }
 
-        if (mEnableCacheDebugInfo)
+    if (mEnableCacheDebugInfo)
+    {
+        auto end_time = std::chrono::high_resolution_clock::now();
+        auto execute_time = std::chrono::duration_cast<std::chrono::milliseconds>(end_time - start_time).count();
+
+        // Log afterward so it doesn't affect the time measurement
+        // Logging thousands of file results can take hundreds of milliseconds
+        for (size_t i = 0; i < file_info.size(); ++i)
         {
+            const file_info_t& entry = file_info[i];
+            const bool removed = file_removed[i];
+            const std::string action = removed ? "DELETE:" : "KEEP:";
+
             // have to do this because of LL_INFO/LL_END weirdness
             std::ostringstream line;
 
@@ -163,12 +180,7 @@ void LLDiskCache::purge()
             line << " (" << file_size_total << "/" << mMaxSizeBytes << ")";
             LL_INFOS() << line.str() << LL_ENDL;
         }
-    }
 
-    if (mEnableCacheDebugInfo)
-    {
-        auto end_time = std::chrono::high_resolution_clock::now();
-        auto execute_time = std::chrono::duration_cast<std::chrono::milliseconds>(end_time - start_time).count();
         LL_INFOS() << "Total dir size after purge is " << dirFileSize(mCacheDir) << LL_ENDL;
         LL_INFOS() << "Cache purge took " << execute_time << " ms to execute for " << file_info.size() << " files" << LL_ENDL;
     }