* 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
ThreadPoolClientBranch
Justin Clarke Casey 2008-02-20 17:34:10 +00:00
parent 96edcea3ae
commit 877713999c
6 changed files with 91 additions and 33 deletions

View File

@ -116,7 +116,7 @@ namespace OpenSim.Framework.Communications.Cache
public void Clear() public void Clear()
{ {
m_log.Info("[ASSETSTORAGE]: Clearing Asset cache"); m_log.Info("[ASSET CACHE]: Clearing Asset cache");
Initialize(); Initialize();
} }
@ -135,7 +135,7 @@ namespace OpenSim.Framework.Communications.Cache
public AssetCache(IAssetServer assetServer) public AssetCache(IAssetServer assetServer)
{ {
m_log.Info("[ASSETSTORAGE]: Creating Asset cache"); m_log.Info("[ASSET CACHE]: Creating Asset cache");
Initialize(); Initialize();
m_assetServer = assetServer; m_assetServer = assetServer;
@ -161,7 +161,7 @@ namespace OpenSim.Framework.Communications.Cache
} }
catch (Exception e) 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; return false;
} }
public void GetAsset(LLUUID assetId, AssetRequestCallback callback) /// <summary>
/// Asynchronously retrieve an asset.
/// </summary>
/// <param name="assetId"></param>
/// <param name="callback">
/// 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</param>
public void GetAsset(LLUUID assetId, AssetRequestCallback callback, bool isTexture)
{ {
AssetBase asset; AssetBase asset;
if (TryGetCachedAsset(assetId, out asset)) if (TryGetCachedAsset(assetId, out asset))
{ {
callback(assetId, asset); callback(assetId, asset);
} }
else else
{ {
NewAssetRequest req = new NewAssetRequest(assetId, callback); NewAssetRequest req = new NewAssetRequest(assetId, callback);
// Make sure we always have a request list to which to add the asset
AssetRequestsList requestList; AssetRequestsList requestList;
lock (RequestLists) lock (RequestLists)
{ {
if (RequestLists.TryGetValue(assetId, out requestList)) 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); requestList.Requests.Add(req);
m_assetServer.RequestAsset(assetId, false); m_assetServer.RequestAsset(assetId, isTexture);
} }
} }
/// <summary> /// <summary>
/// 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. /// load it into the cache.
/// ///
/// XXX We'll keep polling the cache until we get the asset or we exceed /// 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 /// 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 /// 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 /// 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 /// 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. /// asset is much more likely to have made it into the cache.
/// </summary> /// </summary>
@ -276,7 +283,8 @@ namespace OpenSim.Framework.Communications.Cache
} }
} while (--maxPolls > 0); } 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; 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) public AssetBase CopyAsset(LLUUID assetID)
@ -367,9 +375,10 @@ namespace OpenSim.Framework.Communications.Cache
} }
} }
// See IAssetReceiver
public void AssetReceived(AssetBase asset, bool IsTexture) 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 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); TextureImage image = new TextureImage(asset);
if (Textures.ContainsKey(image.FullID)) 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 else
{ {
@ -396,7 +405,7 @@ namespace OpenSim.Framework.Communications.Cache
if (RequestedTextures.ContainsKey(image.FullID)) 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]; AssetRequest req = RequestedTextures[image.FullID];
req.ImageInfo = image; req.ImageInfo = image;
@ -413,7 +422,7 @@ namespace OpenSim.Framework.Communications.Cache
AssetInfo assetInf = new AssetInfo(asset); AssetInfo assetInf = new AssetInfo(asset);
if (Assets.ContainsKey(assetInf.FullID)) 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 else
{ {
@ -426,7 +435,7 @@ namespace OpenSim.Framework.Communications.Cache
if (RequestedAssets.ContainsKey(assetInf.FullID)) 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]; AssetRequest req = RequestedAssets[assetInf.FullID];
req.AssetInf = assetInf; req.AssetInf = assetInf;
@ -455,10 +464,15 @@ namespace OpenSim.Framework.Communications.Cache
} }
} }
// See IAssetReceiver
public void AssetNotFound(LLUUID assetID) 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; AssetRequest req;
if (RequestedTextures.TryGetValue(assetID, out req)) if (RequestedTextures.TryGetValue(assetID, out req))
@ -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); 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) private int CalculateNumPackets(byte[] data)

View File

@ -37,7 +37,8 @@ namespace OpenSim.Framework.Communications.Cache
{ {
public abstract class AssetServerBase : IAssetServer 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 IAssetReceiver m_receiver;
protected BlockingQueue<AssetRequest> m_assetRequests; protected BlockingQueue<AssetRequest> m_assetRequests;
@ -70,13 +71,13 @@ namespace OpenSim.Framework.Communications.Cache
if (asset != null) 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); m_receiver.AssetReceived(asset, req.IsTexture);
} }
else 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); m_receiver.AssetNotFound(req.AssetID);
} }
@ -131,7 +132,7 @@ namespace OpenSim.Framework.Communications.Cache
req.IsTexture = isTexture; req.IsTexture = isTexture;
m_assetRequests.Enqueue(req); 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) public virtual void UpdateAsset(AssetBase asset)

View File

@ -46,7 +46,17 @@ namespace OpenSim.Framework
// could change to delegate? // could change to delegate?
public interface IAssetReceiver public interface IAssetReceiver
{ {
/// <summary>
/// Call back made when a requested asset has been retrieved by an asset server
/// </summary>
/// <param name="asset"></param>
/// <param name="IsTexture"></param>
void AssetReceived(AssetBase asset, bool IsTexture); void AssetReceived(AssetBase asset, bool IsTexture);
/// <summary>
/// Call back made when an asset server could not retrieve a requested asset
/// </summary>
/// <param name="assetID"></param>
void AssetNotFound(LLUUID assetID); void AssetNotFound(LLUUID assetID);
} }

View File

@ -95,7 +95,7 @@ namespace OpenSim.Region.Environment.Modules
new TextureSender(client, e.DiscardLevel, e.PacketNumber); new TextureSender(client, e.DiscardLevel, e.PacketNumber);
m_textureSenders.Add(e.RequestedAssetID, requestHandler); 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
/// </summary> /// </summary>
/// <param name="textureID"></param> /// <param name="textureID"></param>
/// <param name="asset"></param> /// <param name="asset"></param>
public void TextureCallback(LLUUID textureID, AssetBase asset) public void TextureCallback(LLUUID textureID, AssetBase texture)
{ {
lock (m_textureSenders) lock (m_textureSenders)
{ {
@ -125,10 +125,24 @@ namespace OpenSim.Region.Environment.Modules
if (m_textureSenders.TryGetValue(textureID, out textureSender)) if (m_textureSenders.TryGetValue(textureID, out textureSender))
{ {
if (!textureSender.ImageLoaded) if (null != texture)
{ {
textureSender.TextureReceived(asset); if (!textureSender.ImageLoaded)
EnqueueTextureSender(textureSender); {
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); //m_log.InfoFormat("[TEXTURE SENDER] Removing texture sender with uuid {0}", textureID);

View File

@ -160,7 +160,7 @@ namespace OpenSim.Region.Environment.Scenes
cache.GetAsset(item.AssetID, delegate(LLUUID assetID, AssetBase asset) cache.GetAsset(item.AssetID, delegate(LLUUID assetID, AssetBase asset)
{ {
if (asset.FullID == LLUUID.Zero) if (null == asset)
{ {
m_log.ErrorFormat( m_log.ErrorFormat(
"[PRIMINVENTORY]: " + "[PRIMINVENTORY]: " +
@ -174,7 +174,7 @@ namespace OpenSim.Region.Environment.Scenes
m_parentGroup.AddActiveScriptCount(1); m_parentGroup.AddActiveScriptCount(1);
ScheduleFullUpdate(); ScheduleFullUpdate();
} }
}); }, false);
} }
} }

View File

@ -363,9 +363,14 @@ namespace OpenSim.Region.Environment.Scenes
{ {
m_otherMS += ms; m_otherMS += ms;
} }
// private static readonly log4net.ILog m_log
// = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);
public void addPendingDownload(int count) public void addPendingDownload(int count)
{ {
m_pendingDownloads += count; m_pendingDownloads += count;
//m_log.InfoFormat("Adding {0} to pending downloads to make {1}", count, m_pendingDownloads);
} }
public void addScriptLines(int count) public void addScriptLines(int count)