Updating the flotsam asset cache. Thank you, mcortez!

Fixes Mantis #3784

OpenSim/Region/CoreModules/Asset/FlotsamAssetCache.cs

@@ -1,29 +1,32 @@
 /*
- * Copyright (c) Contributors, http://opensimulator.org/
+Copyright (c) Contributors, http://osflotsam.org/
- * See CONTRIBUTORS.TXT for a full list of copyright holders.
+See CONTRIBUTORS.TXT for a full list of copyright holders.
- *
+
- * Redistribution and use in source and binary forms, with or without
+Redistribution and use in source and binary forms, with or without
- * modification, are permitted provided that the following conditions are met:
+modification, are permitted provided that the following conditions are met:
- *     * Redistributions of source code must retain the above copyright
+    * Redistributions of source code must retain the above copyright
- *       notice, this list of conditions and the following disclaimer.
+      notice, this list of conditions and the following disclaimer.
- *     * Redistributions in binary form must reproduce the above copyright
+    * Redistributions in binary form must reproduce the above copyright
- *       notice, this list of conditions and the following disclaimer in the
+      notice, this list of conditions and the following disclaimer in the
- *       documentation and/or other materials provided with the distribution.
+      documentation and/or other materials provided with the distribution.
- *     * Neither the name of the OpenSim Project nor the
+    * Neither the name of the Flotsam Project nor the
- *       names of its contributors may be used to endorse or promote products
+      names of its contributors may be used to endorse or promote products
- *       derived from this software without specific prior written permission.
+      derived from this software without specific prior written permission.
- *
+
- * THIS SOFTWARE IS PROVIDED BY THE DEVELOPERS ``AS IS'' AND ANY
+THIS SOFTWARE IS PROVIDED BY THE DEVELOPERS ``AS IS'' AND ANY EXPRESS OR
- * EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED
+IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED
- * WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE
+WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE
- * DISCLAIMED. IN NO EVENT SHALL THE CONTRIBUTORS BE LIABLE FOR ANY
+DISCLAIMED. IN NO EVENT SHALL THE CONTRIBUTORS BE LIABLE FOR ANY
- * DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES
+DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
- * (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES;
+DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE
- * LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND
+GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
- * ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER
- * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS
+IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR
- * SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF
- */
+ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. */
+
+// Uncomment to make asset Get requests for existing 
+// #define WAIT_ON_INPROGRESS_REQUESTS
 
 using System;
 using System.IO;
@@ -34,21 +37,21 @@ using System.Runtime.Serialization.Formatters.Binary;
 using System.Threading;
 using System.Timers;
 
-
-using GlynnTucker.Cache;
 using log4net;
 using Nini.Config;
 using Mono.Addins;
+using OpenMetaverse;
 
 using OpenSim.Framework;
 using OpenSim.Region.Framework.Interfaces;
 using OpenSim.Region.Framework.Scenes;
 using OpenSim.Services.Interfaces;
 
-[assembly: Addin("FlotsamAssetCache", "1.0")]
+
+[assembly: Addin("FlotsamAssetCache", "1.1")]
 [assembly: AddinDependency("OpenSim", "0.5")]
 
-namespace OpenSim.Region.CoreModules.Asset
+namespace Flotsam.RegionModules.AssetCache
 {
     /// <summary>
     /// OpenSim.ini Options:
@@ -60,6 +63,17 @@ namespace OpenSim.Region.CoreModules.Asset
     ///    ; cache directory can be shared by multiple instances
     ///    CacheDirectory = /directory/writable/by/OpenSim/instance
     ///    
+    ///    ; Log level
+    ///    ; 0 - (Error) Errors only
+    ///    ; 1 - (Info)  Hit Rate Stats + Level 0
+    ///    ; 2 - (Debug) Cache Activity (Reads/Writes) + Level 1
+    ///    ;
+    ///    LogLevel = 1
+    /// 
+    ///    ; How often should hit rates be displayed (given in AssetRequests)
+    ///    ; 0 to disable
+    ///    HitRateDisplay = 100
+    /// 
     ///    ; Set to false for disk cache only.
     ///    MemoryCacheEnabled = true
     ///    
@@ -73,6 +87,11 @@ namespace OpenSim.Region.CoreModules.Asset
     ///    ; How often {in hours} should the disk be checked for expired filed
     ///    ; Specify 0 to disable expiration checking
     ///    FileCleanupTimer = .166  ;roughly every 10 minutes
+    ///    
+    ///    ; If WAIT_ON_INPROGRESS_REQUESTS has been defined then this specifies how 
+    ///    ; long (in miliseconds) to block a request thread while trying to complete 
+    ///    ; writing to disk.
+    ///    WaitOnInprogressTimeout = 3000
     /// -------
     /// </summary>
 
@@ -92,19 +111,24 @@ namespace OpenSim.Region.CoreModules.Asset
 
         private List<char> m_InvalidChars = new List<char>();
 
-        private uint m_DebugRate = 1; // How often to display hit statistics, given in requests
+        private int m_LogLevel = 1;
+        private ulong m_HitRateDisplay = 1; // How often to display hit statistics, given in requests
 
         private static ulong m_Requests = 0;
-        private static ulong m_FileHits = 0;
+        private static ulong m_RequestsForInprogress = 0;
+        private static ulong m_DiskHits = 0;
         private static ulong m_MemoryHits = 0;
         private static double m_HitRateMemory = 0.0;
         private static double m_HitRateFile = 0.0;
 
+#if WAIT_ON_INPROGRESS_REQUESTS
+        private Dictionary<string, ManualResetEvent> m_CurrentlyWriting = new Dictionary<string, ManualResetEvent>();
+        private int m_WaitOnInprogressTimeout = 3000;
+#else
         private List<string> m_CurrentlyWriting = new List<string>();
+#endif
 
-        delegate void AsyncWriteDelegate(string file, AssetBase obj);
+        private ExpiringCache<string, AssetBase> m_MemoryCache = new ExpiringCache<string, AssetBase>();
-
-        private ICache m_MemoryCache = new GlynnTucker.Cache.SimpleMemoryCache();
         private bool m_MemoryCacheEnabled = true;
 
         // Expiration is expressed in hours.
@@ -134,7 +158,6 @@ namespace OpenSim.Region.CoreModules.Asset
             if (moduleConfig != null)
             {
                 string name = moduleConfig.GetString("AssetCaching", this.Name);
-                m_log.DebugFormat("[XXX] name = {0} (this module's name: {1}", name, Name);
 
                 if (name == Name)
                 {
@@ -155,6 +178,11 @@ namespace OpenSim.Region.CoreModules.Asset
                     m_MemoryCacheEnabled = assetConfig.GetBoolean("MemoryCacheEnabled", true);
                     m_MemoryExpiration = TimeSpan.FromHours(assetConfig.GetDouble("MemoryCacheTimeout", m_DefaultMemoryExpiration));
 
+#if WAIT_ON_INPROGRESS_REQUESTS
+                    m_WaitOnInprogressTimeout = assetConfig.GetInt("WaitOnInprogressTimeout", 3000);
+#endif
+
+                    m_HitRateDisplay = (ulong)assetConfig.GetInt("HitRateDisplay", 1);
 
                     m_FileExpiration = TimeSpan.FromHours(assetConfig.GetDouble("FileCacheTimeout", m_DefaultFileExpiration));
                     m_FileExpirationCleanupTimer = TimeSpan.FromHours(assetConfig.GetDouble("FileCleanupTimer", m_DefaultFileExpiration));
@@ -210,7 +238,7 @@ namespace OpenSim.Region.CoreModules.Asset
                 }
                 else
                 {
-                    m_MemoryCache.AddOrUpdate(key, asset);
+                    m_MemoryCache.AddOrUpdate(key, asset, DateTime.MaxValue);
                 }
             }
         }
@@ -237,6 +265,17 @@ namespace OpenSim.Region.CoreModules.Asset
                         // same file multiple times.
                         lock (m_CurrentlyWriting)
                         {
+#if WAIT_ON_INPROGRESS_REQUESTS
+                            if (m_CurrentlyWriting.ContainsKey(filename))
+                            {
+                                return;
+                            }
+                            else
+                            {
+                                m_CurrentlyWriting.Add(filename, new ManualResetEvent(false));
+                            }
+
+#else
                             if (m_CurrentlyWriting.Contains(filename))
                             {
                                 return;
@@ -245,25 +284,21 @@ namespace OpenSim.Region.CoreModules.Asset
                             {
                                 m_CurrentlyWriting.Add(filename);
                             }
+#endif
+
                         }
 
-                        // Setup the actual writing so that it happens asynchronously
+                        ThreadPool.QueueUserWorkItem(
-                        AsyncWriteDelegate awd = delegate( string file, AssetBase obj )
+                            delegate
                             {
-                            WriteFileCache(file, obj);
+                                WriteFileCache(filename, asset);
-                        };
+                            }
-
+                        );
-                        // Go ahead and cache it to disk
-                        awd.BeginInvoke(filename, asset, null, null);
                     }
                 }
                 catch (Exception e)
                 {
-                    string[] text = e.ToString().Split(new char[] { '\n' });
+                    LogException(e);
-                    foreach (string t in text)
-                    {
-                        m_log.InfoFormat("[ASSET CACHE]: {0} ", t);
-                    }
                 }
             }
         }
@@ -274,18 +309,16 @@ namespace OpenSim.Region.CoreModules.Asset
 
             AssetBase asset = null;
 
-            object obj;
+            if (m_MemoryCacheEnabled && m_MemoryCache.TryGetValue(id, out asset))
-            if (m_MemoryCacheEnabled && m_MemoryCache.TryGet(id, out obj))
             {
-                asset = (AssetBase)obj;
                 m_MemoryHits++;
             }
             else
-            {
-                try
             {
                 string filename = GetFileName(id);
                 if (File.Exists(filename))
+                {
+                    try
                     {
                         FileStream stream = File.Open(filename, FileMode.Open);
                         BinaryFormatter bformatter = new BinaryFormatter();
@@ -295,31 +328,64 @@ namespace OpenSim.Region.CoreModules.Asset
 
                         UpdateMemoryCache(id, asset);
 
-                        m_FileHits++;
+                        m_DiskHits++;
                     }
+                    catch (System.Runtime.Serialization.SerializationException e)
+                    {
+                        LogException(e);
+
+                        // If there was a problem deserializing the asset, the asset may 
+                        // either be corrupted OR was serialized under an old format 
+                        // {different version of AssetBase} -- we should attempt to
+                        // delete it and re-cache
+                        File.Delete(filename);
                     }
                     catch (Exception e)
                     {
-                    string[] text = e.ToString().Split(new char[] { '\n' });
+                        LogException(e);
-                    foreach (string t in text)
-                    {
-                        m_log.InfoFormat("[ASSET CACHE]: {0} ", t);
-                    }
                     }
                 }
 
-            if (m_Requests % m_DebugRate == 0)
-            {
-                m_HitRateFile = (double)m_FileHits / m_Requests * 100.0;
 
-                m_log.DebugFormat("[ASSET CACHE]: Cache Get :: {0} :: {1}", id, asset == null ? "Miss" : "Hit");
+#if WAIT_ON_INPROGRESS_REQUESTS
-                m_log.DebugFormat("[ASSET CACHE]: File Hit Rate {0}% for {1} requests", m_HitRateFile.ToString("0.00"), m_Requests);
+                // Check if we're already downloading this asset.  If so, try to wait for it to 
+                // download.
+                if (m_WaitOnInprogressTimeout > 0)
+                {
+                    m_RequestsForInprogress++;
+
+                    ManualResetEvent waitEvent;
+                    if (m_CurrentlyWriting.TryGetValue(filename, out waitEvent))
+                    {
+                        waitEvent.WaitOne(m_WaitOnInprogressTimeout);
+                        return Get(id);
+                    }
+                }
+#else
+                // Track how often we have the problem that an asset is requested while
+                // it is still being downloaded by a previous request.
+                if (m_CurrentlyWriting.Contains(filename))
+                {
+                    m_RequestsForInprogress++;
+                }
+#endif
+            }
+
+            if (((m_LogLevel >= 1)) && (m_HitRateDisplay != 0) && (m_Requests % m_HitRateDisplay == 0))
+            {
+                m_HitRateFile = (double)m_DiskHits / m_Requests * 100.0;
+
+                m_log.InfoFormat("[ASSET CACHE]: Cache Get :: {0} :: {1}", id, asset == null ? "Miss" : "Hit");
+                m_log.InfoFormat("[ASSET CACHE]: File Hit Rate {0}% for {1} requests", m_HitRateFile.ToString("0.00"), m_Requests);
 
                 if (m_MemoryCacheEnabled)
                 {
                     m_HitRateMemory = (double)m_MemoryHits / m_Requests * 100.0;
-                    m_log.DebugFormat("[ASSET CACHE]: Memory Hit Rate {0}% for {1} requests", m_HitRateMemory.ToString("0.00"), m_Requests);
+                    m_log.InfoFormat("[ASSET CACHE]: Memory Hit Rate {0}% for {1} requests", m_HitRateMemory.ToString("0.00"), m_Requests);
                 }
+
+                m_log.InfoFormat("[ASSET CACHE]: {0} unnessesary requests due to requests for assets that are currently downloading.", m_RequestsForInprogress);
+                
             }
 
             return asset;
@@ -327,6 +393,9 @@ namespace OpenSim.Region.CoreModules.Asset
 
         public void Expire(string id)
         {
+            if (m_LogLevel >= 2)
+                m_log.DebugFormat("[ASSET CACHE]: Expiring Asset {0}.", id);
+
             try
             {
                 string filename = GetFileName(id);
@@ -340,16 +409,15 @@ namespace OpenSim.Region.CoreModules.Asset
             }
             catch (Exception e)
             {
-                string[] text = e.ToString().Split(new char[] { '\n' });
+                LogException(e);
-                foreach (string t in text)
-                {
-                    m_log.InfoFormat("[ASSET CACHE]: {0} ", t);
-                }
             }
         }
 
         public void Clear()
         {
+            if (m_LogLevel >= 2)
+                m_log.Debug("[ASSET CACHE]: Clearing Cache.");
+
             foreach (string dir in Directory.GetDirectories(m_CacheDirectory))
             {
                 Directory.Delete(dir);
@@ -361,6 +429,9 @@ namespace OpenSim.Region.CoreModules.Asset
 
         private void CleanupExpiredFiles(object source, ElapsedEventArgs e)
         {
+            if (m_LogLevel >= 2)
+                m_log.DebugFormat("[ASSET CACHE]: Checking for expired files older then {0}.", m_FileExpiration.ToString());
+
             foreach (string dir in Directory.GetDirectories(m_CacheDirectory))
             {
                 foreach (string file in Directory.GetFiles(dir))
@@ -408,16 +479,12 @@ namespace OpenSim.Region.CoreModules.Asset
                 // Now that it's written, rename it so that it can be found.
                 File.Move(tempname, filename);
 
+                if (m_LogLevel >= 2)
                     m_log.DebugFormat("[ASSET CACHE]: Cache Stored :: {0}", asset.ID);
             }
             catch (Exception e)
             {
-                string[] text = e.ToString().Split(new char[] { '\n' });
+                LogException(e);
-                foreach (string t in text)
-                {
-                    m_log.InfoFormat("[ASSET CACHE]: {0} ", t);
-                }
-
             }
             finally
             {
@@ -426,13 +493,31 @@ namespace OpenSim.Region.CoreModules.Asset
                 // cached
                 lock (m_CurrentlyWriting)
                 {
+#if WAIT_ON_INPROGRESS_REQUESTS
+                    ManualResetEvent waitEvent;
+                    if (m_CurrentlyWriting.TryGetValue(filename, out waitEvent))
+                    {
+                        m_CurrentlyWriting.Remove(filename);
+                        waitEvent.Set();
+                    }
+#else
                     if (m_CurrentlyWriting.Contains(filename))
                     {
                         m_CurrentlyWriting.Remove(filename);
                     }
+#endif
                 }
 
             }
         }
+
+        private static void LogException(Exception e)
+        {
+            string[] text = e.ToString().Split(new char[] { '\n' });
+            foreach (string t in text)
+            {
+                m_log.ErrorFormat("[ASSET CACHE]: {0} ", t);
+            }
+        }
     }
 }

bin/config-include/GridCommon.ini.example

@@ -5,31 +5,38 @@
     AssetCaching = "FlotsamAssetCache"
     
 [AssetCache]
-    ;; ---- Optional configurations for FlotsamAssetCache
+    ; cache directory can be shared by multiple instances
-    ;
+    CacheDirectory = /directory/writable/by/OpenSim/instance
-    ; The cache directory can be shared by multiple instances,
-    ; so you may want to change this! Note that you can 
-    ; specify an absolute path (starting with '/'). 
-    ; See examples in comments.
-    ; Make sure the directory you specify can be created.
-    ;
-    CacheDirectory = ./assetcache
-    ;
-    ; Some other examples:
-    ; CacheDirectory = /var/opensim/assetcache ; (Windows and linux)
-    ; CacheDirectory = ~/assetcache ; (Windows and linux)
-    ; CacheDirectory = C:\opensim\assetcache ; (Windows only)
 
+    ; Log level
+    ; 0 - (Error) Errors only
+    ; 1 - (Info)  Hit Rate Stats + Level 0
+    ; 2 - (Debug) Cache Activity (Reads/Writes) + Level 1
     ;
-    ; How long {in hours} to keep assets cached on disk, 
+    LogLevel = 0
-    ; .5 == 30 minutes; 168 = 7 days
+
+    ; How often should hit rates be displayed (given in AssetRequests)
+    ; 0 to disable
+    HitRateDisplay = 100
+
+    ; Set to false for disk cache only.
+    MemoryCacheEnabled = true
+
+    ; How long {in hours} to keep assets cached in memory, .5 == 30 minutes
+    MemoryCacheTimeout = 2
+
+    ; How long {in hours} to keep assets cached on disk, .5 == 30 minutes
     ; Specify 0 if you do not want your disk cache to expire
-    ;
+    FileCacheTimeout = 0
-    FileCacheTimeout = 168 
 
+    ; How often {in hours} should the disk be checked for expired filed
+    ; Specify 0 to disable expiration checking
+    FileCleanupTimer = .166  ;roughly every 10 minutes
     
-    ;; --------- endof FlotsamAssetCache --------
+    ; If WAIT_ON_INPROGRESS_REQUESTS has been defined then this specifies how 
-
+    ; long (in miliseconds) to block a request thread while trying to complete 
+    ; an existing write to disk.
+    ; WaitOnInprogressTimeout = 3000
 
 [AssetService]