Fix http://opensimulator.org/mantis/view.php?id=4224

This resolves the problem where eyes and hair would turn white on standalone configurations
When a client receives body part information, for some insane reason or other it always ends up uploading this back to the server and then immediately re-requesting it.
This should have been okay since we stored that asset in cache.  However, the standalone asset service connector was not checking this cache properly, so every time the client made the request for the asset it has just loaded it would get a big fat null back in the face, causing it to make clothes and hair white.
This bug did not affect grids since they use a different service connector.

5 files changed, 65 insertions, 46 deletions

diff --git a/OpenSim/Region/CoreModules/Agent/AssetTransaction/AssetTransactionModule.cs b/OpenSim/Region/CoreModules/Agent/AssetTransaction/AssetTransactionModule.cs
index 1077f4a..7e08ecf 100644
--- a/OpenSim/Region/CoreModules/Agent/AssetTransaction/AssetTransactionModule.cs
+++ b/OpenSim/Region/CoreModules/Agent/AssetTransaction/AssetTransactionModule.cs
@@ -27,6 +27,8 @@
 
 using System;
 using System.Collections.Generic;
+using System.Reflection;
+using log4net;
 using Nini.Config;
 using OpenMetaverse;
 using OpenSim.Framework;
@@ -37,6 +39,8 @@ namespace OpenSim.Region.CoreModules.Agent.AssetTransaction
 {
     public class AssetTransactionModule : IRegionModule, IAgentAssetTransactions
     {
+//        private static readonly ILog m_log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType);
+        
         private readonly Dictionary<UUID, Scene> RegisteredScenes = new Dictionary<UUID, Scene>();
         private bool m_dumpAssetsToFile = false;
         private Scene m_scene = null;
@@ -226,7 +230,8 @@ namespace OpenSim.Region.CoreModules.Agent.AssetTransaction
         public void HandleUDPUploadRequest(IClientAPI remoteClient, UUID assetID, UUID transaction, sbyte type,
                                            byte[] data, bool storeLocal, bool tempFile)
         {
-            //m_log.Debug("HandleUDPUploadRequest - assetID: " + assetID.ToString() + " transaction: " + transaction.ToString() + " type: " + type.ToString() + " storelocal: " + storeLocal + " tempFile: " + tempFile);
+//            m_log.Debug("HandleUDPUploadRequest - assetID: " + assetID.ToString() + " transaction: " + transaction.ToString() + " type: " + type.ToString() + " storelocal: " + storeLocal + " tempFile: " + tempFile);
+            
             if (((AssetType)type == AssetType.Texture ||
                 (AssetType)type == AssetType.Sound ||
                 (AssetType)type == AssetType.TextureTGA ||
@@ -246,7 +251,6 @@ namespace OpenSim.Region.CoreModules.Agent.AssetTransaction
                 }
             }
 
-            //m_log.Debug("asset upload of " + assetID);
             AgentAssetTransactions transactions = GetUserTransactions(remoteClient.AgentId);
 
             AssetXferUploader uploader = transactions.RequestXferUploader(transaction);
diff --git a/OpenSim/Region/CoreModules/Agent/AssetTransaction/AssetXferUploader.cs b/OpenSim/Region/CoreModules/Agent/AssetTransaction/AssetXferUploader.cs
index f698ea1..fa92fe8 100644
--- a/OpenSim/Region/CoreModules/Agent/AssetTransaction/AssetXferUploader.cs
+++ b/OpenSim/Region/CoreModules/Agent/AssetTransaction/AssetXferUploader.cs
@@ -154,7 +154,8 @@ namespace OpenSim.Region.CoreModules.Agent.AssetTransaction
                 m_userTransactions.Manager.MyScene.AssetService.Store(m_asset);
             }
 
-            m_log.DebugFormat("[ASSET TRANSACTIONS]: Uploaded asset data for transaction {0}", TransactionID);
+            m_log.DebugFormat(
+                "[ASSET TRANSACTIONS]: Uploaded asset {0} for transaction {1}", m_asset.FullID, TransactionID);
 
             if (m_dumpAssetToFile)
             {
diff --git a/OpenSim/Region/CoreModules/Asset/CenomeAssetCache.cs b/OpenSim/Region/CoreModules/Asset/CenomeAssetCache.cs
index 1add0ab..1903eb9 100644
--- a/OpenSim/Region/CoreModules/Asset/CenomeAssetCache.cs
+++ b/OpenSim/Region/CoreModules/Asset/CenomeAssetCache.cs
@@ -91,6 +91,8 @@ namespace OpenSim.Region.CoreModules.Asset
     /// </example>
     public class CenomeMemoryAssetCache : IImprovedAssetCache, ISharedRegionModule
     {
+        private static readonly ILog m_log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType);
+        
         /// <summary>
         /// Cache's default maximal asset count.
         /// </summary>
@@ -115,12 +117,7 @@ namespace OpenSim.Region.CoreModules.Asset
         /// Asset's default expiration time in the cache.
         /// </summary>
         public static readonly TimeSpan DefaultExpirationTime = TimeSpan.FromMinutes(30.0);
-
-        /// <summary>
-        /// Log manager instance.
-        /// </summary>
-        private static readonly ILog Log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType);
-
+        
         /// <summary>
         /// Cache object.
         /// </summary>
@@ -170,7 +167,7 @@ namespace OpenSim.Region.CoreModules.Asset
         {
             if (maximalSize <= 0 || maximalCount <= 0)
             {
-                //Log.Debug("[ASSET CACHE]: Cenome asset cache is not enabled.");
+                //m_log.Debug("[ASSET CACHE]: Cenome asset cache is not enabled.");
                 m_enabled = false;
                 return;
             }
@@ -186,7 +183,7 @@ namespace OpenSim.Region.CoreModules.Asset
                 CnmSynchronizedCache<string, AssetBase>.Synchronized(new CnmMemoryCache<string, AssetBase>(
                     maximalSize, maximalCount, expirationTime));
             m_enabled = true;
-            Log.DebugFormat(
+            m_log.DebugFormat(
                 "[ASSET CACHE]: Cenome asset cache enabled (MaxSize = {0} bytes, MaxCount = {1}, ExpirationTime = {2})",
                 maximalSize,
                 maximalCount,
@@ -205,6 +202,8 @@ namespace OpenSim.Region.CoreModules.Asset
         {
             if (asset != null)
             {
+//                m_log.DebugFormat("[CENOME ASSET CACHE]: Caching asset {0}", asset.ID);
+                
                 long size = asset.Data != null ? asset.Data.Length : 1;
                 m_cache.Set(asset.ID, asset, size);
                 m_cachedCount++;
@@ -255,7 +254,7 @@ namespace OpenSim.Region.CoreModules.Asset
 
             if (m_getCount == m_debugEpoch)
             {
-                Log.DebugFormat(
+                m_log.DebugFormat(
                     "[ASSET CACHE]: Cached = {0}, Get = {1}, Hits = {2}%, Size = {3} bytes, Avg. A. Size = {4} bytes",
                     m_cachedCount,
                     m_getCount,
@@ -267,6 +266,9 @@ namespace OpenSim.Region.CoreModules.Asset
                 m_cachedCount = 0;
             }
 
+//            if (null == assetBase)
+//                m_log.DebugFormat("[CENOME ASSET CACHE]: Asset {0} not in cache", id);
+            
             return assetBase;
         }
 
@@ -325,12 +327,11 @@ namespace OpenSim.Region.CoreModules.Asset
                 return;
 
             string name = moduleConfig.GetString("AssetCaching");
-            //Log.DebugFormat("[XXX] name = {0} (this module's name: {1}", name, Name);
+            //m_log.DebugFormat("[XXX] name = {0} (this module's name: {1}", name, Name);
 
             if (name != Name)
-                return;
-
-            // This module is used 
+                return;           
+            
             long maxSize = DefaultMaxSize;
             int maxCount = DefaultMaxCount;
             TimeSpan expirationTime = DefaultExpirationTime;
diff --git a/OpenSim/Region/CoreModules/ServiceConnectorsOut/Asset/LocalAssetServiceConnector.cs b/OpenSim/Region/CoreModules/ServiceConnectorsOut/Asset/LocalAssetServiceConnector.cs
index fd3aaf4..2f21e6d 100644
--- a/OpenSim/Region/CoreModules/ServiceConnectorsOut/Asset/LocalAssetServiceConnector.cs
+++ b/OpenSim/Region/CoreModules/ServiceConnectorsOut/Asset/LocalAssetServiceConnector.cs
@@ -38,12 +38,9 @@ using OpenSim.Services.Interfaces;
 
 namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Asset
 {
-    public class LocalAssetServicesConnector :
-            ISharedRegionModule, IAssetService
+    public class LocalAssetServicesConnector : ISharedRegionModule, IAssetService
     {
-        private static readonly ILog m_log =
-                LogManager.GetLogger(
-                MethodBase.GetCurrentMethod().DeclaringType);
+        private static readonly ILog m_log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType);
 
         private IImprovedAssetCache m_Cache = null;
 
@@ -72,7 +69,7 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Asset
                     IConfig assetConfig = source.Configs["AssetService"];
                     if (assetConfig == null)
                     {
-                        m_log.Error("[ASSET CONNECTOR]: AssetService missing from OpenSim.ini");
+                        m_log.Error("[LOCAL ASSET SERVICES CONNECTOR]: AssetService missing from OpenSim.ini");
                         return;
                     }
 
@@ -81,22 +78,20 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Asset
 
                     if (serviceDll == String.Empty)
                     {
-                        m_log.Error("[ASSET CONNECTOR]: No LocalServiceModule named in section AssetService");
+                        m_log.Error("[LOCAL ASSET SERVICES CONNECTOR]: No LocalServiceModule named in section AssetService");
                         return;
                     }
 
                     Object[] args = new Object[] { source };
-                    m_AssetService =
-                            ServerUtils.LoadPlugin<IAssetService>(serviceDll,
-                            args);
+                    m_AssetService = ServerUtils.LoadPlugin<IAssetService>(serviceDll, args);
 
                     if (m_AssetService == null)
                     {
-                        m_log.Error("[ASSET CONNECTOR]: Can't load asset service");
+                        m_log.Error("[LOCAL ASSET SERVICES CONNECTOR]: Can't load asset service");
                         return;
                     }
                     m_Enabled = true;
-                    m_log.Info("[ASSET CONNECTOR]: Local asset connector enabled");
+                    m_log.Info("[LOCAL ASSET SERVICES CONNECTOR]: Local asset connector enabled");
                 }
             }
         }
@@ -134,11 +129,11 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Asset
                     m_Cache = null;
             }
 
-            m_log.InfoFormat("[ASSET CONNECTOR]: Enabled local assets for region {0}", scene.RegionInfo.RegionName);
+            m_log.InfoFormat("[LOCAL ASSET SERVICES CONNECTOR]: Enabled local assets for region {0}", scene.RegionInfo.RegionName);
 
             if (m_Cache != null)
             {
-                m_log.InfoFormat("[ASSET CONNECTOR]: Enabled asset caching for region {0}", scene.RegionInfo.RegionName);
+                m_log.InfoFormat("[LOCAL ASSET SERVICES CONNECTOR]: Enabled asset caching for region {0}", scene.RegionInfo.RegionName);
             }
             else
             {
@@ -151,6 +146,8 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Asset
 
         public AssetBase Get(string id)
         {
+//            m_log.DebugFormat("[LOCAL ASSET SERVICES CONNECTOR]: Synchronously requesting asset {0}", id);
+            
             AssetBase asset = null;
             if (m_Cache != null)
                 asset = m_Cache.Get(id);
@@ -160,7 +157,11 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Asset
                 asset = m_AssetService.Get(id);
                 if ((m_Cache != null) && (asset != null))
                     m_Cache.Cache(asset);
+
+//                if (null == asset)
+//                    m_log.WarnFormat("[LOCAL ASSET SERVICES CONNECTOR]: Could not synchronously find asset with id {0}", id);
             }
+            
             return asset;
         }
 
@@ -204,15 +205,17 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Asset
 
         public bool Get(string id, Object sender, AssetRetrieved handler)
         {
-            AssetBase asset = null;
-            
+//            m_log.DebugFormat("[LOCAL ASSET SERVICES CONNECTOR]: Asynchronously requesting asset {0}", id);
+                                    
             if (m_Cache != null)
-                m_Cache.Get(id);
-
-            if (asset != null)
             {
-                Util.FireAndForget(delegate { handler(id, sender, asset); });
-                return true;
+                AssetBase asset = m_Cache.Get(id);
+
+                if (asset != null)
+                {
+                    Util.FireAndForget(delegate { handler(id, sender, asset); });
+                    return true;
+                }
             }
 
             return m_AssetService.Get(id, sender, delegate (string assetID, Object s, AssetBase a)
@@ -220,6 +223,9 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Asset
                 if ((a != null) && (m_Cache != null))
                     m_Cache.Cache(a);
 
+//                if (null == a)
+//                    m_log.WarnFormat("[LOCAL ASSET SERVICES CONNECTOR]: Could not asynchronously find asset with id {0}", id);                
+
                 Util.FireAndForget(delegate { handler(assetID, s, a); });
             });
         }
diff --git a/OpenSim/Region/CoreModules/ServiceConnectorsOut/Inventory/LocalInventoryServiceConnector.cs b/OpenSim/Region/CoreModules/ServiceConnectorsOut/Inventory/LocalInventoryServiceConnector.cs
index 66d11dd..3883dc6 100644
--- a/OpenSim/Region/CoreModules/ServiceConnectorsOut/Inventory/LocalInventoryServiceConnector.cs
+++ b/OpenSim/Region/CoreModules/ServiceConnectorsOut/Inventory/LocalInventoryServiceConnector.cs
@@ -73,7 +73,7 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Inventory
                     IConfig inventoryConfig = source.Configs["InventoryService"];
                     if (inventoryConfig == null)
                     {
-                        m_log.Error("[INVENTORY CONNECTOR]: InventoryService missing from OpenSim.ini");
+                        m_log.Error("[LOCAL INVENTORY SERVICES CONNECTOR]: InventoryService missing from OpenSim.ini");
                         return;
                     }
 
@@ -81,18 +81,18 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Inventory
 
                     if (serviceDll == String.Empty)
                     {
-                        m_log.Error("[INVENTORY CONNECTOR]: No LocalServiceModule named in section InventoryService");
+                        m_log.Error("[LOCAL INVENTORY SERVICES CONNECTOR]: No LocalServiceModule named in section InventoryService");
                         return;
                     }
 
                     Object[] args = new Object[] { source };
-                    m_log.DebugFormat("[INVENTORY CONNECTOR]: Service dll = {0}", serviceDll);
+                    m_log.DebugFormat("[LOCAL INVENTORY SERVICES CONNECTOR]: Service dll = {0}", serviceDll);
 
                     m_InventoryService = ServerUtils.LoadPlugin<IInventoryService>(serviceDll, args);
 
                     if (m_InventoryService == null)
                     {
-                        m_log.Error("[INVENTORY CONNECTOR]: Can't load inventory service");
+                        m_log.Error("[LOCAL INVENTORY SERVICES CONNECTOR]: Can't load inventory service");
                         //return;
                         throw new Exception("Unable to proceed. Please make sure your ini files in config-include are updated according to .example's");
                     }
@@ -111,7 +111,7 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Inventory
                     Init(source);
 
                     m_Enabled = true;
-                    m_log.Info("[INVENTORY CONNECTOR]: Local inventory connector enabled");
+                    m_log.Info("[LOCAL INVENTORY SERVICES CONNECTOR]: Local inventory connector enabled");
                 }
             }
         }
@@ -138,7 +138,7 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Inventory
             }
 
 //            m_log.DebugFormat(
-//                "[INVENTORY CONNECTOR]: Registering IInventoryService to scene {0}", scene.RegionInfo.RegionName);
+//                "[LOCAL INVENTORY SERVICES CONNECTOR]: Registering IInventoryService to scene {0}", scene.RegionInfo.RegionName);
             
             scene.RegisterModuleInterface<IInventoryService>(this);
             m_cache.AddRegion(scene);
@@ -158,7 +158,7 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Inventory
                 return;
 
             m_log.InfoFormat(
-                "[INVENTORY CONNECTOR]: Enabled local invnetory for region {0}", scene.RegionInfo.RegionName);
+                "[LOCAL INVENTORY SERVICES CONNECTOR]: Enabled local inventory for region {0}", scene.RegionInfo.RegionName);
         }
 
         #region IInventoryService
@@ -213,7 +213,7 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Inventory
                     return folders;
                 }
             }
-            m_log.WarnFormat("[INVENTORY CONNECTOR]: System folders for {0} not found", userID);
+            m_log.WarnFormat("[LOCAL INVENTORY SERVICES CONNECTOR]: System folders for {0} not found", userID);
             return new Dictionary<AssetType, InventoryFolderBase>();
         }
 
@@ -312,7 +312,14 @@ namespace OpenSim.Region.CoreModules.ServiceConnectorsOut.Inventory
 
         public override InventoryItemBase GetItem(InventoryItemBase item)
         {
-            return m_InventoryService.GetItem(item);
+//            m_log.DebugFormat("[LOCAL INVENTORY SERVICES CONNECTOR]: Requesting inventory item {0}", item.ID);
+
+            item = m_InventoryService.GetItem(item);
+
+            if (null == item)
+                m_log.ErrorFormat("[LOCAL INVENTORY SERVICES CONNECTOR]: Could not find item with id {0}");
+
+            return item;
         }
 
         public override InventoryFolderBase GetFolder(InventoryFolderBase folder)