feat: loading benchmark analytic

Explorer/Assets/DCL/Infrastructure/Global/AppArgs/AppArgsFlags.cs

@@ -14,6 +14,7 @@ public static class AppArgsFlags
         public const string SCENE_CONSOLE = "scene-console";
 
         public const string AUTOPILOT = "autopilot";
+        public const string MEASURE_LOADING_TIME = "measure-loading-time";
         public const string AUTOPILOT_CSV = "csv";
         public const string AUTOPILOT_SUMMARY = "summary";
         public const string PROFILER_LOG_FILE = "raw";

Explorer/Assets/DCL/Infrastructure/Global/Dynamic/DynamicWorldContainer.cs

@@ -525,7 +525,8 @@ await MapRendererContainer
                 new ProfilingPlugin(staticContainer.Profiler, staticContainer.RealmData,
                     staticContainer.SingletonSharedDependencies.MemoryBudget, debugBuilder,
                     staticContainer.ScenesCache, dclVersion, dynamicSettings.AdaptivePhysicsSettings,
-                    staticContainer.SceneLoadingLimit, appArgs, staticContainer.LoadingStatus),
+                    staticContainer.SceneLoadingLimit, appArgs, staticContainer.LoadingStatus,
+                    bootstrapContainer.Analytics.Controller),
 #if UNITY_EDITOR
                 new RenderingSystemPlugin(debugBuilder),
 #endif

Explorer/Assets/DCL/PerformanceAndDiagnostics/Analytics/AnalyticsEvents.cs

@@ -1,10 +1,6 @@
 namespace DCL.PerformanceAndDiagnostics.Analytics
 {
-    /// <summary>
-    ///     IMPORTANT!!
-    ///     After doing any change to the events here, we need to hit the "Refresh Events" button on the AnalyticsConfiguration Scriptable Object so the new events are recognized!!
-    ///     IMPORTANT!!
-    /// </summary>
+
     public static class AnalyticsEvents
     {
         public static class General
@@ -314,5 +310,10 @@ public static class Places
             public const string PLACE_LINK_COPIED = "place_link_copied";
             public const string PLACE_NAVIGATION_STARTED = "place_navigation_started";
         }
+
+        public static class Profiling
+        {
+            public const string LOADING_TIMES = "synthetic_loading_times";
+        }
     }
 }

Explorer/Assets/DCL/PerformanceAndDiagnostics/LoadingTimes/DCL.Plugins.LoadingTimes.asmref

@@ -0,0 +1,3 @@
+{
+    "reference": "GUID:fc4fd35fb877e904d8cedee73b2256f6"
+}

Explorer/Assets/DCL/PerformanceAndDiagnostics/LoadingTimes/LoadingTimeBenchmark.cs

@@ -0,0 +1,155 @@
+using Cysharp.Threading.Tasks;
+using DCL.Diagnostics;
+using DCL.PerformanceAndDiagnostics.Analytics;
+using DCL.RealmNavigation;
+using DCL.Utility;
+using ECS.SceneLifeCycle;
+using Newtonsoft.Json.Linq;
+using System;
+using System.Collections.Generic;
+using System.Threading;
+using UnityEngine;
+using Utility;
+
+namespace DCL.LoadingTimes
+{
+    /// <summary>
+    ///     CI-only benchmark of the startup loading stages: reports their durations to analytics and quits the client.
+    /// </summary>
+    public sealed class LoadingTimeBenchmark : IDisposable
+    {
+        private const string STAGE_PREFIX = "loading_stage_";
+        private const string START_LABEL = "start_time_s";
+        private const string STOP_LABEL = "stop_time_s";
+        private const string DURATION_LABEL = "duration_s";
+        private const string SCENE_HASH_LABEL = "scene_hash";
+        private const string PLATFORM_LABEL = "platform";
+
+#if UNITY_STANDALONE_OSX
+        private const string PLATFORM_VALUE = "mac";
+#else
+        private const string PLATFORM_VALUE = "win";
+#endif
+
+        // The loading begins with the process, where realtimeSinceStartup is 0.
+        private const float APP_START_TIME = 0f;
+
+        // The analytics service dispatches on a background pump, quitting right away kills the request.
+        private static readonly TimeSpan ANALYTICS_DELIVERY_GRACE = TimeSpan.FromSeconds(5);
+
+        private readonly List<StageMeasure> measures = new ((int)LoadingStatus.LoadingStage.Completed + 1);
+        private readonly CancellationTokenSource cts = new ();
+
+        private readonly ILoadingStatus loadingStatus;
+        private readonly IAnalyticsController analytics;
+        private readonly IScenesCache scenesCache;
+
+        private bool reportRequestFired;
+
+        public LoadingTimeBenchmark(ILoadingStatus loadingStatus, IAnalyticsController analytics, IScenesCache scenesCache)
+        {
+            this.loadingStatus = loadingStatus;
+            this.analytics = analytics;
+            this.scenesCache = scenesCache;
+
+            // Init is set before this subscription exists, so it can only be measured from the app start.
+            measures.Add(new StageMeasure
+            {
+                Stage = LoadingStatus.LoadingStage.Init,
+                StartTime = APP_START_TIME,
+                StopTime = APP_START_TIME,
+            });
+
+            loadingStatus.CurrentStageMut.OnUpdate += OnStageUpdated;
+        }
+
+        public void Dispose()
+        {
+            loadingStatus.CurrentStageMut.OnUpdate -= OnStageUpdated;
+            cts.SafeCancelAndDispose();
+        }
+
+        private void OnStageUpdated(LoadingStatus.LoadingStage stage)
+        {
+            if (reportRequestFired) return;
+
+            AddSample(stage);
+
+            if (stage != LoadingStatus.LoadingStage.Completed) return;
+
+            reportRequestFired = true;
+            ReportAndQuitAsync(scenesCache.CurrentScene.Value?.Info.Name).Forget();
+        }
+
+        private void AddSample(LoadingStatus.LoadingStage stage)
+        {
+            float time = UnityEngine.Time.realtimeSinceStartup;
+
+            StageMeasure previous = measures[^1];
+            previous.StopTime = time;
+            measures[^1] = previous;
+
+            measures.Add(new StageMeasure
+            {
+                Stage = stage,
+                StartTime = time,
+                StopTime = time,
+            });
+        }
+
+        private JObject PayloadSnapshot(string? sceneHash)
+        {
+            float stopTime = measures[^1].StopTime;
+
+            var payload = new JObject
+            {
+                { SCENE_HASH_LABEL, sceneHash },
+                { PLATFORM_LABEL, PLATFORM_VALUE },
+                { START_LABEL, APP_START_TIME },
+                { STOP_LABEL, stopTime },
+                { DURATION_LABEL, stopTime - APP_START_TIME },
+            };
+
+            foreach (StageMeasure measure in measures)
+                payload[$"{STAGE_PREFIX}{measure.Stage.ToString().ToLower()}"] = new JObject
+                {
+                    { START_LABEL, measure.StartTime },
+                    { STOP_LABEL, measure.StopTime },
+                    { DURATION_LABEL, measure.StopTime - measure.StartTime },
+                };
+
+            return payload;
+        }
+
+        private async UniTaskVoid ReportAndQuitAsync(string? sceneHash)
+        {
+            try
+            {
+                JObject payload = PayloadSnapshot(sceneHash);
+
+                analytics.Track(AnalyticsEvents.Profiling.LOADING_TIMES, payload, true);
+                ReportHub.LogProductionInfo(payload.ToString());
+
+                await UniTask.Delay(ANALYTICS_DELIVERY_GRACE, cancellationToken: cts.Token);
+            }
+            catch (OperationCanceledException)
+            {
+                // Disposal means the shutdown is already under way, quitting again would be redundant.
+                return;
+            }
+            catch (Exception e)
+            {
+                ReportHub.LogException(e, ReportCategory.ANALYTICS);
+            }
+
+            ExitUtils.Exit();
+        }
+
+        private struct StageMeasure
+        {
+            public LoadingStatus.LoadingStage Stage;
+            public float StartTime;
+            public float StopTime;
+        }
+    }
+}

Explorer/Assets/DCL/PerformanceAndDiagnostics/SentryTransactionManager.cs

@@ -8,8 +8,6 @@
 using System;
 using System.Collections.Generic;
 using System.Linq;
-using System.Net.Http;
-using UnityEngine;
 using Utility.Multithreading;
 
 namespace DCL.PerformanceAndDiagnostics

Explorer/Assets/DCL/PluginSystem/Global/ProfilingPlugin.cs

@@ -1,8 +1,10 @@
 using Arch.SystemGroups;
 using Cysharp.Threading.Tasks;
 using DCL.DebugUtilities;
+using DCL.LoadingTimes;
 using DCL.Optimization.AdaptivePerformance.Systems;
 using DCL.Optimization.PerformanceBudgeting;
+using DCL.PerformanceAndDiagnostics.Analytics;
 using DCL.PerformanceAndDiagnostics.AutoPilot;
 using DCL.Profiling;
 using DCL.Profiling.ECS;
@@ -27,11 +29,12 @@ public class ProfilingPlugin : IDCLGlobalPluginWithoutSettings
         private readonly SceneLoadingLimit sceneLoadingLimit;
         private readonly IAppArgs appArgs;
         private readonly ILoadingStatus loadingStatus;
+        private readonly LoadingTimeBenchmark? loadingTimeBenchmark;
 
         public ProfilingPlugin(IProfiler profiler, IRealmData realmData, MemoryBudget memoryBudget,
             IDebugContainerBuilder debugContainerBuilder, IScenesCache scenesCache, DCLVersion dclVersion,
             AdaptivePhysicsSettings adaptivePhysicsSettings, SceneLoadingLimit sceneLoadingLimit,
-            IAppArgs appArgs, ILoadingStatus loadingStatus)
+            IAppArgs appArgs, ILoadingStatus loadingStatus, IAnalyticsController analytics)
         {
             this.profiler = profiler;
             this.realmData = realmData;
@@ -43,11 +46,15 @@ public ProfilingPlugin(IProfiler profiler, IRealmData realmData, MemoryBudget me
             this.memoryBudget = memoryBudget;
             this.appArgs = appArgs;
             this.loadingStatus = loadingStatus;
+
+            if (appArgs.HasFlag(AppArgsFlags.MEASURE_LOADING_TIME))
+                loadingTimeBenchmark = new LoadingTimeBenchmark(loadingStatus, analytics, scenesCache);
         }
 
         public void Dispose()
         {
             profiler.Dispose();
+            loadingTimeBenchmark?.Dispose();
         }
 
         public void InjectToWorld(ref ArchSystemsWorldBuilder<Arch.Core.World> builder, in GlobalPluginArguments arguments)

Explorer/Assets/DCL/UserInAppInitializationFlow/RealUserInAppInitializationFlow.cs

@@ -127,14 +127,15 @@ public async UniTask ExecuteAsync(UserInAppInitializationFlowParameters paramete
 
                 bool shouldShowAuthentication = parameters.ShowAuthentication &&
                                                 !appArgs.HasFlagWithValueTrue(AppArgsFlags.SKIP_AUTH_SCREEN) &&
-                                                !appArgs.HasFlag(AppArgsFlags.AUTOPILOT);
+                                                !appArgs.HasFlag(AppArgsFlags.AUTOPILOT) &&
+                                                !appArgs.HasFlag(AppArgsFlags.MEASURE_LOADING_TIME);
 
                 // Force show authentication if there's no valid identity in the cache
                 if (!shouldShowAuthentication)
                     shouldShowAuthentication = identityCache.Identity == null || identityCache.Identity.IsExpired;
 
                 // Only a human user can authenticate currently.
-                if (shouldShowAuthentication && appArgs.HasFlag(AppArgsFlags.AUTOPILOT))
+                if (shouldShowAuthentication && (appArgs.HasFlag(AppArgsFlags.AUTOPILOT) || appArgs.HasFlag(AppArgsFlags.MEASURE_LOADING_TIME)))
                     Application.Quit(1);
 
                 if (shouldShowAuthentication)
@@ -230,14 +231,14 @@ await UniTask.WhenAll(
 
                 result = loadingResult;
 
-                if (result.Success == false)
+                if (!result.Success)
                 {
                     //Fail straight away
                     string message = result.Error.AsMessage();
                     ReportHub.LogError(ReportCategory.AUTHENTICATION, message);
                 }
             }
-            while (result.Success == false && parameters.ShowAuthentication);
+            while (!result.Success && parameters.ShowAuthentication);
         }
 
         private async UniTask VerifyWorldAccessAndFallbackIfNeededAsync(CancellationToken ct)