From 877713999ce9bcf63e9fafa76cc7d2283ee2e6c2 Mon Sep 17 00:00:00 2001 From: Justin Clarke Casey Date: Wed, 20 Feb 2008 17:34:10 +0000 Subject: [PATCH] * Report 'asset not found' situations back to UserTextureDownloadService * This fixes some of the 'runaway downloads' problem but not all of it * Also fix up logging messages so texture requests are reported as such rather than as assets --- .../Communications/Cache/AssetCache.cs | 70 +++++++++++++------ .../Communications/Cache/AssetServerBase.cs | 9 +-- OpenSim/Framework/IAssetServer.cs | 12 +++- .../Modules/UserTextureDownloadService.cs | 24 +++++-- .../Scenes/SceneObjectPart.Inventory.cs | 4 +- .../Environment/Scenes/SimStatsReporter.cs | 5 ++ 6 files changed, 91 insertions(+), 33 deletions(-) diff --git a/OpenSim/Framework/Communications/Cache/AssetCache.cs b/OpenSim/Framework/Communications/Cache/AssetCache.cs index dacb321ec3..049df0cca9 100644 --- a/OpenSim/Framework/Communications/Cache/AssetCache.cs +++ b/OpenSim/Framework/Communications/Cache/AssetCache.cs @@ -116,7 +116,7 @@ namespace OpenSim.Framework.Communications.Cache public void Clear() { - m_log.Info("[ASSETSTORAGE]: Clearing Asset cache"); + m_log.Info("[ASSET CACHE]: Clearing Asset cache"); Initialize(); } @@ -135,7 +135,7 @@ namespace OpenSim.Framework.Communications.Cache public AssetCache(IAssetServer assetServer) { - m_log.Info("[ASSETSTORAGE]: Creating Asset cache"); + m_log.Info("[ASSET CACHE]: Creating Asset cache"); Initialize(); m_assetServer = assetServer; @@ -161,7 +161,7 @@ namespace OpenSim.Framework.Communications.Cache } catch (Exception e) { - m_log.Error("[ASSETCACHE]: " + e.ToString()); + m_log.Error("[ASSET CACHE]: " + e.ToString()); } } } @@ -204,21 +204,28 @@ namespace OpenSim.Framework.Communications.Cache return false; } - public void GetAsset(LLUUID assetId, AssetRequestCallback callback) + /// + /// Asynchronously retrieve an asset. + /// + /// + /// + /// A callback invoked when the asset has either been found or not found. + /// If the asset was found this is called with the asset UUID and the asset data + /// If the asset was not found this is still called with the asset UUID but with a null asset data reference + public void GetAsset(LLUUID assetId, AssetRequestCallback callback, bool isTexture) { AssetBase asset; if (TryGetCachedAsset(assetId, out asset)) { - callback(assetId, asset); } else { NewAssetRequest req = new NewAssetRequest(assetId, callback); + // Make sure we always have a request list to which to add the asset AssetRequestsList requestList; - lock (RequestLists) { if (RequestLists.TryGetValue(assetId, out requestList)) @@ -231,22 +238,22 @@ namespace OpenSim.Framework.Communications.Cache } } - m_log.DebugFormat("[ASSETCACHE]: Added request for asset {0}", assetId); + m_log.DebugFormat("[ASSET CACHE]: Added request for {0} {1}", isTexture ? "texture" : "asset", assetId); requestList.Requests.Add(req); - m_assetServer.RequestAsset(assetId, false); + m_assetServer.RequestAsset(assetId, isTexture); } } /// - /// Get an asset. If the asset isn't in the cache, a request will be made to the persistent store to + /// Synchronously retreive an asset. If the asset isn't in the cache, a request will be made to the persistent store to /// load it into the cache. /// /// XXX We'll keep polling the cache until we get the asset or we exceed /// the allowed number of polls. This isn't a very good way of doing things since a single thread /// is processing inbound packets, so if the asset server is slow, we could block this for up to /// the timeout period. What we might want to do is register asynchronous callbacks on asset - /// receipt in the same manner as the nascent (but not yet active) TextureDownloadModule. Of course, + /// receipt in the same manner as the TextureDownloadModule. Of course, /// a timeout before asset receipt usually isn't fatal, the operation will work on the retry when the /// asset is much more likely to have made it into the cache. /// @@ -276,7 +283,8 @@ namespace OpenSim.Framework.Communications.Cache } } while (--maxPolls > 0); - m_log.WarnFormat("[ASSETCACHE]: Asset {0} was not received before the retrieval timeout was reached", assetID.ToString()); + m_log.WarnFormat("[ASSET CACHE]: {0} {1} was not received before the retrieval timeout was reached", + isTexture ? "texture" : "asset", assetID.ToString()); return null; } @@ -348,7 +356,7 @@ namespace OpenSim.Framework.Communications.Cache } } - m_log.InfoFormat("[ASSETCACHE]: Adding {0} {1} [{2}]: {3}.", temporary, type, asset.FullID, result); + m_log.InfoFormat("[ASSET CACHE]: Adding {0} {1} [{2}]: {3}.", temporary, type, asset.FullID, result); } public AssetBase CopyAsset(LLUUID assetID) @@ -367,9 +375,10 @@ namespace OpenSim.Framework.Communications.Cache } } + // See IAssetReceiver public void AssetReceived(AssetBase asset, bool IsTexture) { - m_log.InfoFormat("[ASSETCACHE]: Recieved {0} [{1}]", IsTexture ? "texture" : "asset", asset.FullID); + m_log.InfoFormat("[ASSET CACHE]: Recieved {0} [{1}]", IsTexture ? "texture" : "asset", asset.FullID); if (asset.FullID != LLUUID.Zero) // if it is set to zero then the asset wasn't found by the server { @@ -383,7 +392,7 @@ namespace OpenSim.Framework.Communications.Cache TextureImage image = new TextureImage(asset); if (Textures.ContainsKey(image.FullID)) { - m_log.InfoFormat("[ASSETCACHE]: There's already an texture {0} in memory. Skipping.", asset.FullID); + m_log.InfoFormat("[ASSET CACHE]: There's already an texture {0} in memory. Skipping.", asset.FullID); } else { @@ -396,7 +405,7 @@ namespace OpenSim.Framework.Communications.Cache if (RequestedTextures.ContainsKey(image.FullID)) { - m_log.InfoFormat("[ASSETCACHE]: Moving {0} from RequestedTextures to TextureRequests", asset.FullID); + m_log.InfoFormat("[ASSET CACHE]: Moving {0} from RequestedTextures to TextureRequests", asset.FullID); AssetRequest req = RequestedTextures[image.FullID]; req.ImageInfo = image; @@ -413,7 +422,7 @@ namespace OpenSim.Framework.Communications.Cache AssetInfo assetInf = new AssetInfo(asset); if (Assets.ContainsKey(assetInf.FullID)) { - m_log.InfoFormat("[ASSETCACHE]: There's already an asset {0} in memory. Skipping.", asset.FullID); + m_log.InfoFormat("[ASSET CACHE]: There's already an asset {0} in memory. Skipping.", asset.FullID); } else { @@ -426,7 +435,7 @@ namespace OpenSim.Framework.Communications.Cache if (RequestedAssets.ContainsKey(assetInf.FullID)) { - m_log.InfoFormat("[ASSETCACHE]: Moving {0} from RequestedAssets to AssetRequests", asset.FullID); + m_log.InfoFormat("[ASSET CACHE]: Moving {0} from RequestedAssets to AssetRequests", asset.FullID); AssetRequest req = RequestedAssets[assetInf.FullID]; req.AssetInf = assetInf; @@ -455,12 +464,17 @@ namespace OpenSim.Framework.Communications.Cache } } + // See IAssetReceiver public void AssetNotFound(LLUUID assetID) { - //m_log.ErrorFormat("[ASSET CACHE]: Unhandled AssetNotFound for {0}", assetID); - + //m_log.ErrorFormat("[ASSET CACHE]: AssetNotFound for {0}", assetID); + + // The 'image not found' packet needs to happen, but RequestedTextures is not actually used (should be cleaned up) + // It might also be better to do this in the TextureDownloadModule + /* + * AssetRequest req; - + if (RequestedTextures.TryGetValue(assetID, out req)) { m_log.WarnFormat("[ASSET CACHE]: sending image not found for {0}", assetID); @@ -473,6 +487,20 @@ namespace OpenSim.Framework.Communications.Cache { m_log.ErrorFormat("[ASSET CACHE]: Asset [{0}] not found, but couldn't find any users to send to ", assetID); } + */ + + // Notify callers + lock (RequestLists) + { + AssetRequestsList reqList = RequestLists[assetID]; + foreach (NewAssetRequest req in reqList.Requests) + { + req.Callback(assetID, null); + } + + RequestLists.Remove(assetID); + reqList.Requests.Clear(); + } } private int CalculateNumPackets(byte[] data) @@ -726,4 +754,4 @@ namespace OpenSim.Framework.Communications.Cache } } } -} \ No newline at end of file +} diff --git a/OpenSim/Framework/Communications/Cache/AssetServerBase.cs b/OpenSim/Framework/Communications/Cache/AssetServerBase.cs index 9d9bc1e61b..8e670b5757 100644 --- a/OpenSim/Framework/Communications/Cache/AssetServerBase.cs +++ b/OpenSim/Framework/Communications/Cache/AssetServerBase.cs @@ -37,7 +37,8 @@ namespace OpenSim.Framework.Communications.Cache { public abstract class AssetServerBase : IAssetServer { - private static readonly log4net.ILog m_log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType); + private static readonly log4net.ILog m_log + = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType); protected IAssetReceiver m_receiver; protected BlockingQueue m_assetRequests; @@ -70,13 +71,13 @@ namespace OpenSim.Framework.Communications.Cache if (asset != null) { - //m_log.InfoFormat("[ASSET]: Asset {0} received from asset server", req.AssetID); + //m_log.InfoFormat("[ASSETSERVER]: Asset {0} received from asset server", req.AssetID); m_receiver.AssetReceived(asset, req.IsTexture); } else { - m_log.ErrorFormat("[ASSET]: Asset {0} not found by asset server", req.AssetID); + m_log.ErrorFormat("[ASSETSERVER]: Asset {0} not found by asset server", req.AssetID); m_receiver.AssetNotFound(req.AssetID); } @@ -131,7 +132,7 @@ namespace OpenSim.Framework.Communications.Cache req.IsTexture = isTexture; m_assetRequests.Enqueue(req); - m_log.InfoFormat("[ASSET]: Added {0} to request queue", assetID); + m_log.InfoFormat("[ASSETSERVER]: Added {0} to request queue", assetID); } public virtual void UpdateAsset(AssetBase asset) diff --git a/OpenSim/Framework/IAssetServer.cs b/OpenSim/Framework/IAssetServer.cs index df36623785..cbf0759bf0 100644 --- a/OpenSim/Framework/IAssetServer.cs +++ b/OpenSim/Framework/IAssetServer.cs @@ -46,7 +46,17 @@ namespace OpenSim.Framework // could change to delegate? public interface IAssetReceiver { + /// + /// Call back made when a requested asset has been retrieved by an asset server + /// + /// + /// void AssetReceived(AssetBase asset, bool IsTexture); + + /// + /// Call back made when an asset server could not retrieve a requested asset + /// + /// void AssetNotFound(LLUUID assetID); } @@ -54,4 +64,4 @@ namespace OpenSim.Framework { IAssetServer GetAssetServer(); } -} \ No newline at end of file +} diff --git a/OpenSim/Region/Environment/Modules/UserTextureDownloadService.cs b/OpenSim/Region/Environment/Modules/UserTextureDownloadService.cs index 4a94266112..24f0981be4 100644 --- a/OpenSim/Region/Environment/Modules/UserTextureDownloadService.cs +++ b/OpenSim/Region/Environment/Modules/UserTextureDownloadService.cs @@ -95,7 +95,7 @@ namespace OpenSim.Region.Environment.Modules new TextureSender(client, e.DiscardLevel, e.PacketNumber); m_textureSenders.Add(e.RequestedAssetID, requestHandler); - m_scene.AssetCache.GetAsset(e.RequestedAssetID, TextureCallback); + m_scene.AssetCache.GetAsset(e.RequestedAssetID, TextureCallback, true); } } } @@ -117,7 +117,7 @@ namespace OpenSim.Region.Environment.Modules /// /// /// - public void TextureCallback(LLUUID textureID, AssetBase asset) + public void TextureCallback(LLUUID textureID, AssetBase texture) { lock (m_textureSenders) { @@ -125,10 +125,24 @@ namespace OpenSim.Region.Environment.Modules if (m_textureSenders.TryGetValue(textureID, out textureSender)) { - if (!textureSender.ImageLoaded) + if (null != texture) { - textureSender.TextureReceived(asset); - EnqueueTextureSender(textureSender); + if (!textureSender.ImageLoaded) + { + textureSender.TextureReceived(texture); + EnqueueTextureSender(textureSender); + } + } + else + { + // Right now, leaving it up to lower level asset server code to post the fact that + // this texture could not be found + + // TODO Send packet back to the client telling it not to expect the texture + // The absence of this packet doesn't appear to be causing it a problem right now + + //m_log.InfoFormat("Removing {0} from pending downloads count", textureID); + m_scene.AddPendingDownloads(-1); } //m_log.InfoFormat("[TEXTURE SENDER] Removing texture sender with uuid {0}", textureID); diff --git a/OpenSim/Region/Environment/Scenes/SceneObjectPart.Inventory.cs b/OpenSim/Region/Environment/Scenes/SceneObjectPart.Inventory.cs index 17c4d6d141..dc95002fec 100644 --- a/OpenSim/Region/Environment/Scenes/SceneObjectPart.Inventory.cs +++ b/OpenSim/Region/Environment/Scenes/SceneObjectPart.Inventory.cs @@ -160,7 +160,7 @@ namespace OpenSim.Region.Environment.Scenes cache.GetAsset(item.AssetID, delegate(LLUUID assetID, AssetBase asset) { - if (asset.FullID == LLUUID.Zero) + if (null == asset) { m_log.ErrorFormat( "[PRIMINVENTORY]: " + @@ -174,7 +174,7 @@ namespace OpenSim.Region.Environment.Scenes m_parentGroup.AddActiveScriptCount(1); ScheduleFullUpdate(); } - }); + }, false); } } diff --git a/OpenSim/Region/Environment/Scenes/SimStatsReporter.cs b/OpenSim/Region/Environment/Scenes/SimStatsReporter.cs index a0539f0a8f..422189e029 100644 --- a/OpenSim/Region/Environment/Scenes/SimStatsReporter.cs +++ b/OpenSim/Region/Environment/Scenes/SimStatsReporter.cs @@ -363,9 +363,14 @@ namespace OpenSim.Region.Environment.Scenes { m_otherMS += ms; } + +// private static readonly log4net.ILog m_log +// = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType); + public void addPendingDownload(int count) { m_pendingDownloads += count; + //m_log.InfoFormat("Adding {0} to pending downloads to make {1}", count, m_pendingDownloads); } public void addScriptLines(int count)