* Start recording asset request times after a cache miss. This is very primtive at the moment - only the last time is kept for some classes of request

* This can be seen as "Latest asset request time after cache miss" in show stats on the region console

OpenSim/Framework/Communications/Cache/AssetCache.cs

@@ -268,8 +268,11 @@ namespace OpenSim.Framework.Communications.Cache
                     {
                         // m_log.DebugFormat("[ASSET CACHE]: Adding request for {0} {1}", isTexture ? "texture" : "asset", assetId);
                         requestList = new AssetRequestsList(assetId);
-                        RequestLists.Add(assetId, requestList);
+                        requestList.TimeRequested = DateTime.Now;
                         requestList.Requests.Add(req);           
+                        
+                        RequestLists.Add(assetId, requestList);                        
+                        
                         m_assetServer.RequestAsset(assetId, isTexture);
                     }
                 }
@@ -446,6 +449,9 @@ namespace OpenSim.Framework.Communications.Cache
 
             if (reqList != null)
             {
+                if (StatsManager.SimExtraStats != null)
+                    StatsManager.SimExtraStats.AddAssetRequestTimeAfterCacheMiss(DateTime.Now - reqList.TimeRequested);
+                
                 foreach (NewAssetRequest req in reqList.Requests)
                 {
                     // Xantor 20080526 are we really calling all the callbacks if multiple queued for 1 request? -- Yes, checked
@@ -479,6 +485,9 @@ namespace OpenSim.Framework.Communications.Cache
 
             if (reqList != null)
             {
+                if (StatsManager.SimExtraStats != null)
+                    StatsManager.SimExtraStats.AddAssetRequestTimeAfterCacheMiss(DateTime.Now - reqList.TimeRequested);
+                
                 foreach (NewAssetRequest req in reqList.Requests)
                 {
                     req.Callback(assetID, null);
@@ -671,6 +680,11 @@ namespace OpenSim.Framework.Communications.Cache
             public UUID AssetID;
             public List<NewAssetRequest> Requests = new List<NewAssetRequest>();
             
+            /// <summary>
+            /// Record the time that this request was first made.
+            /// </summary>
+            public DateTime TimeRequested;
+
             public AssetRequestsList(UUID assetID)
             {
                 AssetID = assetID;

OpenSim/Framework/Statistics/SimExtraStatsCollector.cs

@@ -45,6 +45,7 @@ namespace OpenSim.Framework.Statistics
         private long texturesInCache;
         private long assetCacheMemoryUsage;
         private long textureCacheMemoryUsage;
+        private TimeSpan assetRequestTimeAfterCacheMiss;
         private long blockedMissingTextureRequests;
 
         private long assetServiceRequestFailures;
@@ -87,6 +88,11 @@ namespace OpenSim.Framework.Statistics
         public long AssetCacheMemoryUsage { get { return assetCacheMemoryUsage; } }
         public long TextureCacheMemoryUsage { get { return textureCacheMemoryUsage; } }
         
+        /// <summary>
+        /// This is the time it took for the last asset request made in response to a cache miss.
+        /// </summary>
+        public TimeSpan AssetRequestTimeAfterCacheMiss { get { return assetRequestTimeAfterCacheMiss; } }
+
         /// <summary>
         /// Number of persistent requests for missing textures we have started blocking from clients.  To some extent
         /// this is just a temporary statistic to keep this problem in view - the root cause of this lies either
@@ -148,7 +154,7 @@ namespace OpenSim.Framework.Statistics
         }
 
         /// <summary>
-        /// Signal that the asset cache can be cleared.
+        /// Signal that the asset cache has been cleared.
         /// </summary>
         public void ClearAssetCacheStatistics()
         {
@@ -158,6 +164,11 @@ namespace OpenSim.Framework.Statistics
             textureCacheMemoryUsage = 0;
         }
         
+        public void AddAssetRequestTimeAfterCacheMiss(TimeSpan ts)
+        {
+            assetRequestTimeAfterCacheMiss = ts;
+        }
+
         public void AddBlockedMissingTextureRequest()
         {
             blockedMissingTextureRequests++;
@@ -245,10 +256,12 @@ namespace OpenSim.Framework.Statistics
                 string.Format(
 @"Asset cache contains   {0,6} non-texture assets using {1,10} K
 Texture cache contains {2,6} texture     assets using {3,10} K
-Blocked client requests for missing textures: {4}
+Latest asset request time after cache miss: {4}s
-Asset service request failures: {5}"+ Environment.NewLine,
+Blocked client requests for missing textures: {5}
+Asset service request failures: {6}"+ Environment.NewLine,
                     AssetsInCache, Math.Round(AssetCacheMemoryUsage / 1024.0),
                     TexturesInCache, Math.Round(TextureCacheMemoryUsage / 1024.0),
+                    assetRequestTimeAfterCacheMiss.Milliseconds / 1000.0,
                     BlockedMissingTextureRequests,
                     AssetServiceRequestFailures));