| | 1 | | using DCL.FPSDisplay; |
| | 2 | | using DCL.SettingsCommon; |
| | 3 | | using MainScripts.DCL.WorldRuntime.Debugging.Performance; |
| | 4 | | using Newtonsoft.Json; |
| | 5 | | using System; |
| | 6 | | using System.Collections.Generic; |
| | 7 | | using System.Linq; |
| | 8 | | using UnityEngine; |
| | 9 | |
|
| | 10 | | namespace DCL |
| | 11 | | { |
| | 12 | | /// <summary> |
| | 13 | | /// Performance Meter Tool |
| | 14 | | /// |
| | 15 | | /// It samples frames performance data for the target duration and prints a complete report when finished. |
| | 16 | | /// |
| | 17 | | /// There are 2 ways to trigger this tool usage: |
| | 18 | | /// A: While the client is running in the browser, open the browser console and run "clientDebug.RunPerformanceMeter |
| | 19 | | /// B: In Unity Editor select the "Main" gameobject and right-click on its DebugBridge Monobehaviour, from there a d |
| | 20 | | /// </summary> |
| | 21 | | public class PerformanceMeterController |
| | 22 | | { |
| | 23 | | private readonly IProfilerRecordsService profilerRecordsService; |
| | 24 | | private readonly PerformanceMetricsDataVariable metricsData; |
| 0 | 25 | | private readonly List<SampleData> samples = new (); |
| | 26 | |
|
| | 27 | | private float currentDurationInSeconds; |
| | 28 | | private float targetDurationInSeconds; |
| | 29 | |
|
| | 30 | | // auxiliar data |
| | 31 | | private SampleData lastSavedSample; |
| | 32 | |
|
| | 33 | | // reported data |
| | 34 | | private double highestFrameTime; |
| | 35 | | private double lowestFrameTime; |
| | 36 | | private double averageFrameTime; |
| | 37 | | private double marginOfError; |
| | 38 | |
|
| | 39 | | private float percentile1FrameTime; |
| | 40 | | private float percentile50FrameTime; |
| | 41 | | private float percentile99FrameTime; |
| | 42 | | private int totalHiccupFrames; |
| | 43 | | private float totalHiccupsTimeInSeconds; |
| | 44 | | private int totalFrames; |
| | 45 | | private float totalFramesTimeInSeconds; |
| | 46 | | private long lowestAllocation; |
| | 47 | | private long highestAllocation; |
| | 48 | | private long averageAllocation; |
| | 49 | | private long totalAllocation; |
| | 50 | |
|
| | 51 | | private bool justStarted; |
| | 52 | |
|
| 0 | 53 | | public PerformanceMeterController() |
| | 54 | | { |
| 0 | 55 | | metricsData = Resources.Load<PerformanceMetricsDataVariable>("ScriptableObjects/PerformanceMetricsData"); |
| 0 | 56 | | profilerRecordsService = Environment.i.serviceLocator.Get<IProfilerRecordsService>(); |
| 0 | 57 | | } |
| | 58 | |
|
| | 59 | | /// <summary> |
| | 60 | | /// Starts the Performance Meter Tool sampling. |
| | 61 | | /// </summary> |
| | 62 | | /// <param name="durationInSeconds">The target duration for the running of the tool, after which a report will b |
| | 63 | | public void StartSampling(float durationInSeconds) |
| | 64 | | { |
| 0 | 65 | | Log("Start running... target duration: " + durationInSeconds + " seconds"); |
| | 66 | |
|
| 0 | 67 | | ResetDataValues(); |
| | 68 | |
|
| 0 | 69 | | targetDurationInSeconds = durationInSeconds; |
| 0 | 70 | | justStarted = true; |
| 0 | 71 | | profilerRecordsService.StartRecordGCAllocatedInFrame(); |
| | 72 | |
|
| 0 | 73 | | metricsData.OnChange += OnMetricsChange; |
| 0 | 74 | | } |
| | 75 | |
|
| | 76 | | private void ResetDataValues() |
| | 77 | | { |
| 0 | 78 | | samples.Clear(); |
| 0 | 79 | | currentDurationInSeconds = 0f; |
| 0 | 80 | | targetDurationInSeconds = 0f; |
| | 81 | |
|
| 0 | 82 | | lastSavedSample = null; |
| | 83 | |
|
| 0 | 84 | | highestFrameTime = 0; |
| 0 | 85 | | lowestFrameTime = 0; |
| 0 | 86 | | averageFrameTime = 0; |
| 0 | 87 | | percentile50FrameTime = 0; |
| 0 | 88 | | percentile99FrameTime = 0; |
| | 89 | |
|
| 0 | 90 | | totalHiccupFrames = 0; |
| 0 | 91 | | totalHiccupsTimeInSeconds = 0; |
| | 92 | |
|
| 0 | 93 | | totalFrames = 0; |
| 0 | 94 | | totalFramesTimeInSeconds = 0; |
| | 95 | |
|
| 0 | 96 | | lowestAllocation = long.MaxValue; |
| 0 | 97 | | highestAllocation = 0; |
| 0 | 98 | | averageAllocation = 0; |
| 0 | 99 | | totalAllocation = 0; |
| 0 | 100 | | } |
| | 101 | |
|
| | 102 | | /// <summary> |
| | 103 | | /// Callback triggered on every update made to the PerformanceMetricsDataVariable ScriptableObject, done every f |
| | 104 | | /// </summary> |
| | 105 | | /// /// <param name="newData">NEW version of the PerformanceMetricsDataVariable ScriptableObject</param> |
| | 106 | | /// /// <param name="oldData">OLD version of the PerformanceMetricsDataVariable ScriptableObject</param> |
| | 107 | | private void OnMetricsChange(PerformanceMetricsData newData, PerformanceMetricsData oldData) |
| | 108 | | { |
| | 109 | | // we avoid the first frame as when we are in editor, the context menu pauses everything and the next frame |
| 0 | 110 | | if (justStarted) |
| | 111 | | { |
| 0 | 112 | | justStarted = false; |
| 0 | 113 | | return; |
| | 114 | | } |
| | 115 | |
|
| 0 | 116 | | float secondsConsumed = 0; |
| | 117 | |
|
| 0 | 118 | | if (lastSavedSample != null) |
| | 119 | | { |
| 0 | 120 | | if (lastSavedSample.frameNumber == Time.frameCount) |
| | 121 | | { |
| 0 | 122 | | Log("PerformanceMetricsDataVariable changed more than once in the same frame!"); |
| 0 | 123 | | return; |
| | 124 | | } |
| | 125 | |
|
| 0 | 126 | | secondsConsumed = Time.timeSinceLevelLoad - lastSavedSample.currentTime; |
| | 127 | | } |
| | 128 | |
|
| 0 | 129 | | var newSample = new SampleData |
| | 130 | | { |
| | 131 | | frameTimeMs = profilerRecordsService.LastFrameTimeInMS, |
| | 132 | | frameNumber = Time.frameCount, |
| | 133 | | millisecondsConsumed = secondsConsumed * 1000, |
| | 134 | | currentTime = Time.timeSinceLevelLoad, |
| | 135 | | isHiccup = LinealBufferHiccupCounter.IsHiccup(secondsConsumed), |
| | 136 | | }; |
| | 137 | |
|
| 0 | 138 | | samples.Add(newSample); |
| 0 | 139 | | lastSavedSample = newSample; |
| | 140 | |
|
| 0 | 141 | | if (newSample.isHiccup) |
| | 142 | | { |
| 0 | 143 | | totalHiccupFrames++; |
| 0 | 144 | | totalHiccupsTimeInSeconds += secondsConsumed; |
| | 145 | | } |
| | 146 | |
|
| 0 | 147 | | UpdateAllocations(); |
| | 148 | |
|
| 0 | 149 | | totalFrames++; |
| | 150 | |
|
| 0 | 151 | | currentDurationInSeconds += Time.deltaTime; |
| | 152 | |
|
| 0 | 153 | | if (currentDurationInSeconds > targetDurationInSeconds) |
| | 154 | | { |
| 0 | 155 | | totalFramesTimeInSeconds = currentDurationInSeconds; |
| 0 | 156 | | StopSampling(); |
| | 157 | | } |
| 0 | 158 | | } |
| | 159 | |
|
| | 160 | | private void UpdateAllocations() |
| | 161 | | { |
| 0 | 162 | | long lastAllocation = profilerRecordsService.GcAllocatedInFrame; |
| | 163 | |
|
| 0 | 164 | | if (highestAllocation < lastAllocation) |
| 0 | 165 | | highestAllocation = lastAllocation; |
| | 166 | |
|
| 0 | 167 | | if (lowestAllocation > lastAllocation) |
| 0 | 168 | | lowestAllocation = lastAllocation; |
| | 169 | |
|
| 0 | 170 | | totalAllocation += lastAllocation; |
| 0 | 171 | | } |
| | 172 | |
|
| | 173 | | /// <summary> |
| | 174 | | /// Stops the Performance Meter Tool sampling, processes the data gathered and prints a full report in the conso |
| | 175 | | /// </summary> |
| | 176 | | public void StopSampling() |
| | 177 | | { |
| 0 | 178 | | Log("Stopped running."); |
| | 179 | |
|
| 0 | 180 | | profilerRecordsService.StopRecordGCAllocatedInFrame(); |
| 0 | 181 | | metricsData.OnChange -= OnMetricsChange; |
| | 182 | |
|
| 0 | 183 | | if (samples.Count == 0) |
| | 184 | | { |
| 0 | 185 | | Log("No samples were gathered, the duration time in seconds set is probably too small"); |
| 0 | 186 | | return; |
| | 187 | | } |
| | 188 | |
|
| 0 | 189 | | ProcessSamples(); |
| 0 | 190 | | ReportData(); |
| 0 | 191 | | } |
| | 192 | |
|
| | 193 | | /// <summary> |
| | 194 | | /// Process the data gathered from every frame sample to calculate the final highestFPS, lowestFPS, averageFPS, |
| | 195 | | /// </summary> |
| | 196 | | private void ProcessSamples() |
| | 197 | | { |
| | 198 | | // Sort the samples based on FPS count of each one, to be able to calculate the percentiles later |
| 0 | 199 | | var sortedSamples = new List<SampleData>(samples); |
| 0 | 200 | | sortedSamples.Sort(); |
| | 201 | |
|
| 0 | 202 | | int samplesCount = sortedSamples.Count; |
| | 203 | |
|
| 0 | 204 | | var benchmark = new BenchmarkResult(sortedSamples.Select(sample => (double)sample.frameTimeMs).ToArray()); |
| | 205 | |
|
| 0 | 206 | | highestFrameTime = benchmark.max; |
| 0 | 207 | | lowestFrameTime = benchmark.min; |
| 0 | 208 | | averageFrameTime = benchmark.mean; |
| 0 | 209 | | marginOfError = benchmark.rme; |
| | 210 | |
|
| 0 | 211 | | percentile1FrameTime = sortedSamples[Mathf.Min(Mathf.CeilToInt(samplesCount * 0.01f), sortedSamples.Count - |
| 0 | 212 | | percentile50FrameTime = sortedSamples[Mathf.Min(Mathf.CeilToInt(samplesCount * 0.5f), sortedSamples.Count - |
| 0 | 213 | | percentile99FrameTime = sortedSamples[Mathf.Min(Mathf.CeilToInt(samplesCount * 0.99f), sortedSamples.Count - |
| | 214 | |
|
| 0 | 215 | | averageAllocation = totalAllocation / sortedSamples.Count; |
| 0 | 216 | | } |
| | 217 | |
|
| | 218 | | /// <summary> |
| | 219 | | /// Formats and prints the final data report following the 3 steps: system info, processed values and frame samp |
| | 220 | | /// </summary> |
| | 221 | | private void ReportData() |
| | 222 | | { |
| | 223 | | // TODO: We could build a text file (or html) template with replaceable tags like #OPERATING_SYSTEM, #GRAPHI |
| | 224 | |
|
| | 225 | | // Step 1 - report relevant system info: hardware, cappedFPS, OS, sampling duration, etc. |
| 0 | 226 | | Log("Data report step 1 - System and Graphics info:" |
| | 227 | | + "\n * Sampling duration in seconds -> " + targetDurationInSeconds |
| | 228 | | + "\n * System Info -> Operating System -> " + SystemInfo.operatingSystem |
| | 229 | | + "\n * System Info -> Device Name -> " + SystemInfo.deviceName |
| | 230 | | + "\n * System Info -> Graphics Device Name -> " + SystemInfo.graphicsDeviceName |
| | 231 | | + "\n * System Info -> System RAM Size -> " + SystemInfo.systemMemorySize |
| | 232 | | + "\n * General Settings -> Scenes Load Radius -> " + Settings.i.generalSettings.Data.scenesLoadRadius |
| | 233 | | + "\n * Quality Settings -> FPSCap -> " + Settings.i.qualitySettings.Data.fpsCap |
| | 234 | | + "\n * Quality Settings -> Bloom -> " + Settings.i.qualitySettings.Data.bloom |
| | 235 | | + "\n * Quality Settings -> Shadow -> " + Settings.i.qualitySettings.Data.shadows |
| | 236 | | + "\n * Quality Settings -> Antialising -> " + Settings.i.qualitySettings.Data.antiAliasing |
| | 237 | | + "\n * Quality Settings -> Base Resolution -> " + Settings.i.qualitySettings.Data.baseResolution |
| | 238 | | + "\n * Quality Settings -> Display Name -> " + Settings.i.qualitySettings.Data.displayName |
| | 239 | | + "\n * Quality Settings -> Render Scale -> " + Settings.i.qualitySettings.Data.renderScale |
| | 240 | | + "\n * Quality Settings -> Shadow Distance -> " + Settings.i.qualitySettings.Data.shadowDistance |
| | 241 | | + "\n * Quality Settings -> Shadow Resolution -> " + Settings.i.qualitySettings.Data.shadowResolution |
| | 242 | | + "\n * Quality Settings -> Soft Shadows -> " + Settings.i.qualitySettings.Data.softShadows |
| | 243 | | + "\n * Quality Settings -> SSAO Quality -> " + Settings.i.qualitySettings.Data.ssaoQuality |
| | 244 | | + "\n * Quality Settings -> Camera Draw Distance -> " + |
| | 245 | | Settings.i.qualitySettings.Data.cameraDrawDistance |
| | 246 | | + "\n * Quality Settings -> Detail Object Culling Enabled -> " + |
| | 247 | | Settings.i.qualitySettings.Data.enableDetailObjectCulling |
| | 248 | | + "\n * Quality Settings -> Detail Object Culling Limit -> " + |
| | 249 | | Settings.i.qualitySettings.Data.detailObjectCullingLimit |
| | 250 | | + "\n * Quality Settings -> Reflection Quality -> " + |
| | 251 | | Settings.i.qualitySettings.Data.reflectionResolution |
| | 252 | | ); |
| | 253 | |
|
| | 254 | | // Step 2 - report processed data |
| 0 | 255 | | var format = "F1"; |
| | 256 | |
|
| 0 | 257 | | Log("Data report step 2 - Processed values:" + |
| | 258 | | $"\n * PERFORMANCE SCORE (0-100) -> {CalculatePerformanceScore()}" + |
| | 259 | | $"\n * lowest frame time -> {lowestFrameTime.ToString(format)}ms" + |
| | 260 | | $"\n * average frame time -> {averageFrameTime.ToString(format)}ms" + |
| | 261 | | $"\n * highest frame time -> {highestFrameTime.ToString(format)}ms" + |
| | 262 | | $"\n * 1 percentile frame time -> {percentile1FrameTime.ToString(format)}ms" + |
| | 263 | | $"\n * 50 percentile frame time -> {percentile50FrameTime.ToString(format)}ms" + |
| | 264 | | $"\n * 99 percentile frame time -> {percentile99FrameTime.ToString(format)}ms" + |
| | 265 | | $"\n * error percentage -> ±{marginOfError.ToString(format)}%" + |
| | 266 | | $"\n * total hiccups (>{FPSEvaluation.HICCUP_THRESHOLD_IN_SECONDS}ms frames) -> {totalHiccupFrames} ({Ca |
| | 267 | | $"\n * total hiccups time (seconds) -> {totalHiccupsTimeInSeconds}" + |
| | 268 | | $"\n * total frames -> {totalFrames}" + |
| | 269 | | $"\n * total frames time (seconds) -> {totalFramesTimeInSeconds}" + |
| | 270 | | $"\n * lowest allocations (kb) -> {lowestAllocation / 1000.0}" + |
| | 271 | | $"\n * highest allocations (kb) -> {highestAllocation / 1000.0}" + |
| | 272 | | $"\n * average allocations (kb) -> {averageAllocation / 1000.0}" + |
| | 273 | | $"\n * total allocations (kb) -> {totalAllocation / 1000.0}" |
| | 274 | | ); |
| | 275 | |
|
| | 276 | | // Step 3 - report all samples data |
| 0 | 277 | | string rawSamplesJSON = "Data report step 3 - Raw samples:" |
| | 278 | | + "\n " |
| | 279 | | + "{\"frame-samples\": " + JsonConvert.SerializeObject(samples) + "}"; |
| | 280 | |
|
| | 281 | | #if !UNITY_WEBGL && UNITY_EDITOR |
| 0 | 282 | | string targetFilePath = Application.persistentDataPath + "/PerformanceMeterRawFrames.txt"; |
| 0 | 283 | | Log("Data report step 3 - Trying to dump raw samples JSON at: " + targetFilePath); |
| 0 | 284 | | System.IO.File.WriteAllText(targetFilePath, rawSamplesJSON); |
| | 285 | | #endif |
| | 286 | |
|
| 0 | 287 | | Log(rawSamplesJSON); |
| 0 | 288 | | } |
| | 289 | |
|
| | 290 | | /// <summary> |
| | 291 | | /// Calculates a performance score from 0 to 100 based on the average frame time (compared to the closest frame |
| | 292 | | /// </summary> |
| | 293 | | private int CalculatePerformanceScore() |
| | 294 | | { |
| 0 | 295 | | double desiredFrameTime = Settings.i.qualitySettings.Data.fpsCap ? 1000 / 30.0 : 1000 / 60.0; |
| 0 | 296 | | double frameScore = Mathf.Min((float)(desiredFrameTime / averageFrameTime), 1); // from 0 to 1 |
| 0 | 297 | | double hiccupsScore = 1 - ((float)totalHiccupFrames / samples.Count); // from 0 to 1 |
| 0 | 298 | | double performanceScore = (frameScore + hiccupsScore) / 2 * 100; // scores sum / amount of scores * 100 to h |
| | 299 | |
|
| 0 | 300 | | return Mathf.RoundToInt((float)performanceScore * 100f) / 100; |
| | 301 | | } |
| | 302 | |
|
| | 303 | | private float CalculateHiccupsPercentage() |
| | 304 | | { |
| 0 | 305 | | float percentage = (float)totalHiccupFrames / totalFrames * 100; |
| 0 | 306 | | percentage = Mathf.Round(percentage * 100f) / 100f; // to have 2 decimals |
| | 307 | |
|
| 0 | 308 | | return percentage; |
| | 309 | | } |
| | 310 | |
|
| | 311 | | /// <summary> |
| | 312 | | /// Logs the tool messages in console regardless of the "Debug.unityLogger.logEnabled" value. |
| | 313 | | /// </summary> |
| | 314 | | private static void Log(string message) |
| | 315 | | { |
| 0 | 316 | | bool originalLogEnabled = Debug.unityLogger.logEnabled; |
| 0 | 317 | | Debug.unityLogger.logEnabled = true; |
| | 318 | |
|
| 0 | 319 | | Debug.Log("PerformanceMeter - " + message); |
| | 320 | |
|
| 0 | 321 | | Debug.unityLogger.logEnabled = originalLogEnabled; |
| 0 | 322 | | } |
| | 323 | |
|
| | 324 | | private class SampleData : IComparable |
| | 325 | | { |
| | 326 | | public int frameNumber; |
| | 327 | | public float millisecondsConsumed; |
| | 328 | | public bool isHiccup; |
| | 329 | | public float currentTime; |
| | 330 | | public float frameTimeMs; |
| | 331 | |
|
| | 332 | | public override string ToString() => |
| 0 | 333 | | "frame number: " + frameNumber |
| | 334 | | + "\n frame consumed milliseconds: " + millisecondsConsumed |
| | 335 | | + "\n is hiccup: " + isHiccup |
| | 336 | | + "\n frame time: " + frameTimeMs; |
| | 337 | |
|
| | 338 | | public int CompareTo(object obj) |
| | 339 | | { |
| | 340 | | // 0 -> this and otherSample are equal |
| | 341 | | // 1 -> this is greater |
| | 342 | | // -1 -> otherSample is greater |
| | 343 | |
|
| 0 | 344 | | var otherSample = obj as SampleData; |
| | 345 | |
|
| 0 | 346 | | if (otherSample == null) |
| 0 | 347 | | return 1; |
| | 348 | |
|
| 0 | 349 | | if (Math.Abs(frameTimeMs - otherSample.frameTimeMs) < float.Epsilon) |
| 0 | 350 | | return 0; |
| | 351 | |
|
| 0 | 352 | | return frameTimeMs > otherSample.frameTimeMs ? 1 : -1; |
| | 353 | | } |
| | 354 | | } |
| | 355 | | } |
| | 356 | | } |