Optimization: error handling performance spikes (#1979)

* remove ReportStreamableLoadingErrorSystem, log exception on result creation

* IsIrrecoverableError when NOT_FOUND

* move log before the return branch in RepeatLoopAsync

* strict setup AvatarInstantiatorSystemShould

* ExceptionWithNoLogs

* remove ExceptionWithNoLogs

* LogAssert.ignoreFailingMessages = true; for tests

* ignoreFailingMessages

* fix dependencies

* cover other tests with log-assert

* post merge fix

Explorer/Assets/DCL/AvatarRendering/AvatarShape/Systems/AvatarInstantiatorSystem.cs

@@ -88,8 +88,8 @@ protected override void Update(float t)
         {
             if (!ReadyToInstantiateNewAvatar(ref avatarShapeComponent)) return null;
 
-            if (!avatarShapeComponent.WearablePromise.SafeTryConsume(World, out WearablesLoadResult wearablesResult)) return null;
-            if (!avatarShapeComponent.EmotePromise.SafeTryConsume(World, out EmotesLoadResult emotesResult)) return null;
+            if (!avatarShapeComponent.WearablePromise.SafeTryConsume(World, GetReportCategory(), out WearablesLoadResult wearablesResult)) return null;
+            if (!avatarShapeComponent.EmotePromise.SafeTryConsume(World, GetReportCategory(), out EmotesLoadResult emotesResult)) return null;
 
             AvatarBase avatarBase = avatarPoolRegistry.Get();
             avatarBase.gameObject.name = $"Avatar {avatarShapeComponent.ID}";
@@ -139,8 +139,8 @@ private void InstantiateExistingAvatar(ref AvatarShapeComponent avatarShapeCompo
         {
             if (!ReadyToInstantiateNewAvatar(ref avatarShapeComponent)) return;
 
-            if (!avatarShapeComponent.WearablePromise.SafeTryConsume(World, out WearablesLoadResult wearablesResult)) return;
-            if (!avatarShapeComponent.EmotePromise.SafeTryConsume(World, out EmotesLoadResult emotesResult)) return;
+            if (!avatarShapeComponent.WearablePromise.SafeTryConsume(World, GetReportCategory(), out WearablesLoadResult wearablesResult)) return;
+            if (!avatarShapeComponent.EmotePromise.SafeTryConsume(World, GetReportCategory(), out EmotesLoadResult emotesResult)) return;
 
             ReleaseAvatar.Execute(vertOutBuffer, wearableAssetsCache, avatarMaterialPoolHandler, computeShaderSkinningPool, avatarShapeComponent, ref skinningComponent);
 

Explorer/Assets/DCL/AvatarRendering/AvatarShape/Tests/Instantiate/AvatarInstantiatorSystemShould.cs

@@ -4,9 +4,13 @@
 using DCL.AvatarRendering.AvatarShape.Components;
 using DCL.AvatarRendering.AvatarShape.ComputeShader;
 using DCL.AvatarRendering.AvatarShape.Helpers;
+using DCL.AvatarRendering.AvatarShape.Rendering.TextureArray;
+using DCL.AvatarRendering.AvatarShape.Helpers;
 using DCL.AvatarRendering.AvatarShape.Systems;
 using DCL.AvatarRendering.AvatarShape.UnityInterface;
 using DCL.AvatarRendering.Emotes;
+using DCL.AvatarRendering.Wearables;
+using DCL.AvatarRendering.Emotes;
 using DCL.AvatarRendering.Loading.Assets;
 using DCL.AvatarRendering.Loading.Components;
 using DCL.AvatarRendering.Wearables.Components;
@@ -45,8 +49,7 @@ public class AvatarInstantiatorSystemShould : UnitySystemTestBase<AvatarInstanti
         private Color randomEyesColor;
         private Mesh avatarMesh;
 
-        [SetUp]
-        public async void Setup()
+        private async Task SetupAsync()
         {
             IReleasablePerformanceBudget budget = Substitute.For<IReleasablePerformanceBudget>();
             budget.TrySpendBudget().Returns(true);
@@ -184,7 +187,7 @@ private IWearable GetMockWearable(string materialName, string category)
         public async Task InstantiateAvatar()
         {
             // For some reason SetUp is not awaited, probably a Unity's bug
-            await UniTask.WaitUntil(() => system != null && avatarMesh != null);
+            await SetupAsync();
 
             //Arrange
             avatarEntity = world.Create(avatarShapeComponent, PartitionComponent.TOP_PRIORITY, new CharacterTransform());
@@ -235,7 +238,7 @@ public async Task UpdateInstantiatedAvatar()
         public async Task DestroyInstantiatedAvatar()
         {
             // For some reason SetUp is not awaited, probably a Unity's bug
-            await UniTask.WaitUntil(() => system != null && avatarMesh != null);
+            await SetupAsync();
 
             //Arrange
             Entity entity = world.Create(avatarShapeComponent, PartitionComponent.TOP_PRIORITY, new TransformComponent());

Explorer/Assets/DCL/AvatarRendering/Emotes/Systems/FinalizeEmoteLoadingSystem.cs

@@ -51,7 +51,7 @@ ref IEmote emote
                 return;
             }
 
-            if (promise.SafeTryConsume(World!, out StreamableLoadingResult<SceneAssetBundleManifest> result))
+            if (promise.SafeTryConsume(World!, GetReportCategory(), out StreamableLoadingResult<SceneAssetBundleManifest> result))
             {
                 emote.UpdateManifest(result);
                 World!.Destroy(entity);
@@ -67,7 +67,7 @@ ref EmotesFromRealmPromise promise
             if (promise.TryForgetWithEntityIfCancelled(entity, World!))
                 return;
 
-            if (promise.SafeTryConsume(World!, out StreamableLoadingResult<EmotesDTOList> promiseResult))
+            if (promise.SafeTryConsume(World!, GetReportCategory(), out StreamableLoadingResult<EmotesDTOList> promiseResult))
             {
                 if (!promiseResult.Succeeded)
                 {
@@ -96,7 +96,7 @@ private void FinalizeAssetBundleLoading(Entity entity, ref AssetBundlePromise pr
                 return;
             }
 
-            if (promise.SafeTryConsume(World, out StreamableLoadingResult<AssetBundleData> result))
+            if (promise.SafeTryConsume(World, GetReportCategory(), out StreamableLoadingResult<AssetBundleData> result))
             {
                 if (result.Succeeded)
                 {
@@ -126,7 +126,7 @@ private void FinalizeAudioClipPromise(Entity entity, ref IEmote emote, ref Audio
 
             if (promise.IsConsumed) return;
 
-            if (!promise.SafeTryConsume(World!, out StreamableLoadingResult<AudioClip> result))
+            if (!promise.SafeTryConsume(World!, GetReportCategory(), out StreamableLoadingResult<AudioClip> result))
                 return;
 
             if (result.Succeeded)

Explorer/Assets/DCL/AvatarRendering/Emotes/Systems/Load/LoadSceneEmotesSystem.cs

@@ -65,6 +65,7 @@ private void GetEmotesFromRealm([Data] float dt, in Entity entity,
         {
             if (intention.TryCancelByRequest<GetSceneEmoteFromRealmIntention, EmotesResolution>(
                     World!,
+                    GetReportCategory(),
                     entity,
                     static i => $"Scene emote request cancelled {i.EmoteHash}"))
                 return;
@@ -76,7 +77,7 @@ private void GetEmotesFromRealm([Data] float dt, in Entity entity,
                 if (!World.Has<StreamableResult>(entity))
                 {
                     ReportHub.LogWarning(GetReportCategory(), $"Loading scenes emotes timed out {urn}");
-                    World.Add(entity, new StreamableResult(new TimeoutException($"Scene emote timeout {urn}")));
+                    World.Add(entity, new StreamableResult(GetReportCategory(), new TimeoutException($"Scene emote timeout {urn}")));
                 }
 
                 return;
@@ -169,6 +170,7 @@ private void GetEmotesByPointers([Data] float dt, in Entity entity,
         {
             if (intention.TryCancelByRequest<GetEmotesByPointersIntention, EmotesResolution>(
                     World!,
+                    GetReportCategory(),
                     entity,
                     static _ => "Pointer request cancelled"))
                 return;
@@ -288,7 +290,7 @@ private bool TryCancelByTimeout(Entity entity, ref GetEmotesByPointersIntention
                 {
                     var pointersStrLog = string.Join(",", intention.Pointers);
                     ReportHub.LogWarning(GetReportCategory(), $"Loading emotes timed out, {pointersStrLog}");
-                    World.Add(entity, new StreamableResult(new TimeoutException($"Emote intention timeout {pointersStrLog}")));
+                    World.Add(entity, new StreamableResult(GetReportCategory(), new TimeoutException($"Emote intention timeout {pointersStrLog}")));
                 }
 
                 return true;

Explorer/Assets/DCL/AvatarRendering/Loading/Systems/Abstract/FinalizeElementsLoadingSystem.cs

@@ -45,13 +45,16 @@ protected bool TryFinalizeIfCancelled(Entity entity, in AssetPromise<TDTOList, T
         protected void ReportAndFinalizeWithError(URN urn)
         {
             //We have some missing pointers that were not completed. We have to consider them as failure
-            var e = new ArgumentNullException($"Wearable DTO is null for for {urn}");
-            ReportHub.LogError(new ReportData(GetReportCategory()), e);
 
             if (storage.TryGetElement(urn, out var component))
 
                 //If its not in the catalog, we cannot determine which one has failed
-                component.ResolvedFailedDTO(new StreamableLoadingResult<TDTO>(e));
+                component.ResolvedFailedDTO(
+                    new StreamableLoadingResult<TDTO>(
+                        new ReportData(GetReportCategory()),
+                        new ArgumentNullException($"Wearable DTO is null for for {urn}")
+                    )
+                );
         }
     }
 }

Explorer/Assets/DCL/AvatarRendering/Wearables/Helpers/WearablePolymorphicBehaviour.cs

@@ -7,6 +7,7 @@
 using DCL.AvatarRendering.Loading.DTO;
 using DCL.AvatarRendering.Wearables.Components;
 using DCL.AvatarRendering.Wearables.Components.Intentions;
+using DCL.Diagnostics;
 using DCL.Optimization.Pools;
 using ECS.Prioritization.Components;
 using ECS.StreamableLoading.AssetBundles;
@@ -54,7 +55,9 @@ public static bool TryCreateAssetBundlePromise(
             in GetWearablesByPointersIntention intention,
             URLSubdirectory customStreamingSubdirectory,
             IPartitionComponent partitionComponent,
-            World world)
+            World world,
+            ReportData reportData
+        )
         {
             SceneAssetBundleManifest? manifest = !EnumUtils.HasFlag(intention.PermittedSources, AssetSource.WEB) ? null : wearable.ManifestResult?.Asset;
 
@@ -70,7 +73,9 @@ public static bool TryCreateAssetBundlePromise(
                         wearable,
                         partitionComponent,
                         bodyShape,
-                        world);
+                        world,
+                        reportData
+                    );
                 default:
                     return TryCreateSingleGameObjectAssetBundlePromise(
                         manifest,
@@ -79,7 +84,9 @@ public static bool TryCreateAssetBundlePromise(
                         wearable,
                         partitionComponent,
                         bodyShape,
-                        world);
+                        world,
+                        reportData
+                    );
             }
         }
 
@@ -90,11 +97,13 @@ public static bool TryCreateSingleGameObjectAssetBundlePromise(
             IWearable wearable,
             IPartitionComponent partitionComponent,
             BodyShape bodyShape,
-            World world)
+            World world,
+            ReportData reportData
+        )
         {
             ref WearableAssets wearableAssets = ref InitializeResultsArray(wearable, bodyShape, 1);
 
-            return TryCreateMainFilePromise(typeof(GameObject), sceneAssetBundleManifest, intention, customStreamingSubdirectory, wearable, partitionComponent, ref wearableAssets, bodyShape, world);
+            return TryCreateMainFilePromise(typeof(GameObject), sceneAssetBundleManifest, intention, customStreamingSubdirectory, wearable, partitionComponent, ref wearableAssets, bodyShape, world, reportData);
         }
 
         /// <summary>
@@ -107,13 +116,15 @@ private static bool TryCreateFacialFeaturePromises(
             IWearable wearable,
             IPartitionComponent partitionComponent,
             BodyShape bodyShape,
-            World world)
+            World world,
+            ReportData reportData
+        )
         {
             ref WearableAssets wearableAssets = ref InitializeResultsArray(wearable, bodyShape, 2);
 
             // 0 stands for the main texture
             // 1 stands for the mask
-            return TryCreateMainFilePromise(typeof(Texture), sceneAssetBundleManifest, intention, customStreamingSubdirectory, wearable, partitionComponent, ref wearableAssets, bodyShape, world)
+            return TryCreateMainFilePromise(typeof(Texture), sceneAssetBundleManifest, intention, customStreamingSubdirectory, wearable, partitionComponent, ref wearableAssets, bodyShape, world, reportData)
                    | TryCreateMaskPromise(sceneAssetBundleManifest, intention, customStreamingSubdirectory, wearable, partitionComponent, ref wearableAssets, bodyShape, world);
         }
 
@@ -169,8 +180,15 @@ private static bool TryCreateMaskPromise(SceneAssetBundleManifest sceneAssetBund
         private static bool TryCreateMainFilePromise<T>(
             Type expectedObjectType,
             SceneAssetBundleManifest sceneAssetBundleManifest,
-            GetWearablesByPointersIntention intention, URLSubdirectory customStreamingSubdirectory, T wearable,
-            IPartitionComponent partitionComponent, ref WearableAssets wearableAssets, BodyShape bodyShape, World world)
+            GetWearablesByPointersIntention intention,
+            URLSubdirectory customStreamingSubdirectory,
+            T wearable,
+            IPartitionComponent partitionComponent,
+            ref WearableAssets wearableAssets,
+            BodyShape bodyShape,
+            World world,
+            ReportData reportData
+        )
             where T: IAvatarAttachment
         {
             if (wearableAssets.Results[MAIN_ASSET_INDEX] != null)
@@ -179,7 +197,7 @@ private static bool TryCreateMainFilePromise<T>(
             if (!wearable.TryGetMainFileHash(bodyShape, out string? mainFileHash))
             {
                 wearableAssets.Results[MAIN_ASSET_INDEX] =
-                    new StreamableLoadingResult<AttachmentAssetBase>(new Exception("Main file hash not found"));
+                    new StreamableLoadingResult<AttachmentAssetBase>(reportData, new Exception("Main file hash not found"));
 
                 return false;
             }
@@ -223,7 +241,7 @@ private static void CreatePromise<T>(
 
         public static StreamableLoadingResult<AttachmentAssetBase> ToWearableAsset(this StreamableLoadingResult<AssetBundleData> result, IWearable wearable)
         {
-            if (!result.Succeeded) return new StreamableLoadingResult<AttachmentAssetBase>(result.Exception!);
+            if (!result.Succeeded) return new StreamableLoadingResult<AttachmentAssetBase>(result.ReportData, result.Exception!);
 
             switch (wearable.Type)
             {
@@ -264,6 +282,7 @@ public static bool HasEssentialAssetsResolved(this IWearable wearable, BodyShape
             if (wearable.Type == WearableType.FacialFeature)
             {
                 if (results.Length <= 0) return false;
+
                 // Exclude texture mask from required assets
                 StreamableLoadingResult<AttachmentAssetBase>? mainFileAsset = results[0];
                 return mainFileAsset is { Succeeded: true };

Explorer/Assets/DCL/AvatarRendering/Wearables/Systems/FinalizeWearableLoadingSystem.cs

@@ -80,7 +80,7 @@ private void ResolveWearablePromise([Data] bool defaultWearablesResolved, in Ent
         {
             if (wearablesByPointersIntention.CancellationTokenSource.IsCancellationRequested)
             {
-                World!.Add(entity, new StreamableResult(new Exception("Pointer request cancelled")));
+                World!.Add(entity, new StreamableResult(GetReportCategory(), new Exception("Pointer request cancelled")));
                 return;
             }
 
@@ -177,7 +177,7 @@ private void FinalizeWearableDTO(Entity entity, ref AssetPromise<WearablesDTOLis
             if (TryFinalizeIfCancelled(entity, promise))
                 return;
 
-            if (promise.SafeTryConsume(World!, out StreamableLoadingResult<WearablesDTOList> promiseResult))
+            if (promise.SafeTryConsume(World!, GetReportCategory(), out StreamableLoadingResult<WearablesDTOList> promiseResult))
             {
                 if (!promiseResult.Succeeded)
                 {
@@ -222,7 +222,7 @@ private void FinalizeAssetBundleManifestLoading([Data] bool defaultWearablesReso
                 return;
             }
 
-            if (promise.SafeTryConsume(World, out StreamableLoadingResult<SceneAssetBundleManifest> result))
+            if (promise.SafeTryConsume(World, GetReportCategory(), out StreamableLoadingResult<SceneAssetBundleManifest> result))
             {
                 if (result.Succeeded)
                     wearable.ManifestResult = result;
@@ -252,7 +252,7 @@ int index
                 return;
             }
 
-            if (promise.SafeTryConsume(World, out StreamableLoadingResult<AssetBundleData> result))
+            if (promise.SafeTryConsume(World, GetReportCategory(), out StreamableLoadingResult<AssetBundleData> result))
             {
                 // every asset in the batch is mandatory => if at least one has already failed set the default wearables
                 if (result.Succeeded && !AnyAssetHasFailed(wearable, bodyShape))
@@ -282,7 +282,7 @@ private bool CreateAssetBundlePromiseIfRequired(IWearable component, in GetWeara
             if (component.ManifestResult == null && EnumUtils.HasFlag(intention.PermittedSources, AssetSource.WEB))
                 return component.CreateAssetBundleManifestPromise(World, intention.BodyShape, intention.CancellationTokenSource, partitionComponent);
 
-            if (component.TryCreateAssetBundlePromise(in intention, customStreamingSubdirectory, partitionComponent, World))
+            if (component.TryCreateAssetBundlePromise(in intention, customStreamingSubdirectory, partitionComponent, World, GetReportCategory()))
             {
                 component.UpdateLoadingStatus(true);
                 return true;
@@ -305,10 +305,10 @@ private void SetDefaultWearables(bool defaultWearablesLoaded, IWearable wearable
         {
             if (!defaultWearablesLoaded)
             {
-                ReportHub.LogError(GetReportCategory(), $"Default wearable {wearable.DTO.GetHash()} failed to load");
-
-                StreamableLoadingResult<AttachmentAssetBase> failedResult = new StreamableLoadingResult<AssetBundleData>(new Exception("Default wearable failed to load"))
-                   .ToWearableAsset(wearable);
+                StreamableLoadingResult<AttachmentAssetBase> failedResult = new StreamableLoadingResult<AssetBundleData>(
+                    GetReportCategory(),
+                    new Exception($"Default wearable {wearable.DTO.GetHash()} failed to load")
+                ).ToWearableAsset(wearable);
 
                 if (wearable.IsUnisex() && wearable.HasSameModelsForAllGenders())
                 {