AstarProfiler.cs 7.7 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223
  1. //Uncomment the next line to enable debugging (also uncomment it in AstarPath.cs)
  2. //#define ProfileAstar //@SHOWINEDITOR
  3. //#define ASTAR_UNITY_PRO_PROFILER //@SHOWINEDITOR Requires ProfileAstar, profiles section of astar code which will show up in the Unity Pro Profiler.
  4. using System.Collections.Generic;
  5. using System;
  6. using UnityEngine;
  7. using UnityEngine.Profiling;
  8. namespace Pathfinding {
  9. public class AstarProfiler {
  10. public class ProfilePoint {
  11. //public DateTime lastRecorded;
  12. //public TimeSpan totalTime;
  13. public System.Diagnostics.Stopwatch watch = new System.Diagnostics.Stopwatch();
  14. public int totalCalls;
  15. public long tmpBytes;
  16. public long totalBytes;
  17. }
  18. static readonly Dictionary<string, ProfilePoint> profiles = new Dictionary<string, ProfilePoint>();
  19. static DateTime startTime = DateTime.UtcNow;
  20. public static ProfilePoint[] fastProfiles;
  21. public static string[] fastProfileNames;
  22. private AstarProfiler() {
  23. }
  24. [System.Diagnostics.Conditional("ProfileAstar")]
  25. public static void InitializeFastProfile (string[] profileNames) {
  26. fastProfileNames = new string[profileNames.Length+2];
  27. Array.Copy(profileNames, fastProfileNames, profileNames.Length);
  28. fastProfileNames[fastProfileNames.Length-2] = "__Control1__";
  29. fastProfileNames[fastProfileNames.Length-1] = "__Control2__";
  30. fastProfiles = new ProfilePoint[fastProfileNames.Length];
  31. for (int i = 0; i < fastProfiles.Length; i++) fastProfiles[i] = new ProfilePoint();
  32. }
  33. [System.Diagnostics.Conditional("ProfileAstar")]
  34. public static void StartFastProfile (int tag) {
  35. //profiles.TryGetValue(tag, out point);
  36. fastProfiles[tag].watch.Start();//lastRecorded = DateTime.UtcNow;
  37. }
  38. [System.Diagnostics.Conditional("ProfileAstar")]
  39. public static void EndFastProfile (int tag) {
  40. /*if (!profiles.ContainsKey(tag))
  41. * {
  42. * Debug.LogError("Can only end profiling for a tag which has already been started (tag was " + tag + ")");
  43. * return;
  44. * }*/
  45. ProfilePoint point = fastProfiles[tag];
  46. point.totalCalls++;
  47. point.watch.Stop();
  48. //DateTime now = DateTime.UtcNow;
  49. //point.totalTime += now - point.lastRecorded;
  50. //fastProfiles[tag] = point;
  51. }
  52. [System.Diagnostics.Conditional("ASTAR_UNITY_PRO_PROFILER")]
  53. public static void EndProfile () {
  54. Profiler.EndSample();
  55. }
  56. [System.Diagnostics.Conditional("ProfileAstar")]
  57. public static void StartProfile (string tag) {
  58. #if ASTAR_UNITY_PRO_PROFILER
  59. Profiler.BeginSample(tag);
  60. #else
  61. //Console.WriteLine ("Profile Start - " + tag);
  62. ProfilePoint point;
  63. profiles.TryGetValue(tag, out point);
  64. if (point == null) {
  65. point = new ProfilePoint();
  66. profiles[tag] = point;
  67. }
  68. point.tmpBytes = GC.GetTotalMemory(false);
  69. point.watch.Start();
  70. //point.lastRecorded = DateTime.UtcNow;
  71. //Debug.Log ("Starting " + tag);
  72. #endif
  73. }
  74. [System.Diagnostics.Conditional("ProfileAstar")]
  75. public static void EndProfile (string tag) {
  76. #if !ASTAR_UNITY_PRO_PROFILER
  77. if (!profiles.ContainsKey(tag)) {
  78. Debug.LogError("Can only end profiling for a tag which has already been started (tag was " + tag + ")");
  79. return;
  80. }
  81. //Console.WriteLine ("Profile End - " + tag);
  82. //DateTime now = DateTime.UtcNow;
  83. ProfilePoint point = profiles[tag];
  84. //point.totalTime += now - point.lastRecorded;
  85. ++point.totalCalls;
  86. point.watch.Stop();
  87. point.totalBytes += GC.GetTotalMemory(false) - point.tmpBytes;
  88. //profiles[tag] = point;
  89. //Debug.Log ("Ending " + tag);
  90. #else
  91. EndProfile();
  92. #endif
  93. }
  94. [System.Diagnostics.Conditional("ProfileAstar")]
  95. public static void Reset () {
  96. profiles.Clear();
  97. startTime = DateTime.UtcNow;
  98. if (fastProfiles != null) {
  99. for (int i = 0; i < fastProfiles.Length; i++) {
  100. fastProfiles[i] = new ProfilePoint();
  101. }
  102. }
  103. }
  104. [System.Diagnostics.Conditional("ProfileAstar")]
  105. public static void PrintFastResults () {
  106. if (fastProfiles == null)
  107. return;
  108. StartFastProfile(fastProfiles.Length-2);
  109. for (int i = 0; i < 1000; i++) {
  110. StartFastProfile(fastProfiles.Length-1);
  111. EndFastProfile(fastProfiles.Length-1);
  112. }
  113. EndFastProfile(fastProfiles.Length-2);
  114. double avgOverhead = fastProfiles[fastProfiles.Length-2].watch.Elapsed.TotalMilliseconds / 1000.0;
  115. TimeSpan endTime = DateTime.UtcNow - startTime;
  116. var output = new System.Text.StringBuilder();
  117. output.Append("============================\n\t\t\t\tProfile results:\n============================\n");
  118. output.Append("Name | Total Time | Total Calls | Avg/Call | Bytes");
  119. //foreach(KeyValuePair<string, ProfilePoint> pair in profiles)
  120. for (int i = 0; i < fastProfiles.Length; i++) {
  121. string name = fastProfileNames[i];
  122. ProfilePoint value = fastProfiles[i];
  123. int totalCalls = value.totalCalls;
  124. double totalTime = value.watch.Elapsed.TotalMilliseconds - avgOverhead*totalCalls;
  125. if (totalCalls < 1) continue;
  126. output.Append("\n").Append(name.PadLeft(10)).Append("| ");
  127. output.Append(totalTime.ToString("0.0 ").PadLeft(10)).Append(value.watch.Elapsed.TotalMilliseconds.ToString("(0.0)").PadLeft(10)).Append("| ");
  128. output.Append(totalCalls.ToString().PadLeft(10)).Append("| ");
  129. output.Append((totalTime / totalCalls).ToString("0.000").PadLeft(10));
  130. /* output.Append("\nProfile");
  131. * output.Append(name);
  132. * output.Append(" took \t");
  133. * output.Append(totalTime.ToString("0.0"));
  134. * output.Append(" ms to complete over ");
  135. * output.Append(totalCalls);
  136. * output.Append(" iteration");
  137. * if (totalCalls != 1) output.Append("s");
  138. * output.Append(", averaging \t");
  139. * output.Append((totalTime / totalCalls).ToString("0.000"));
  140. * output.Append(" ms per call"); */
  141. }
  142. output.Append("\n\n============================\n\t\tTotal runtime: ");
  143. output.Append(endTime.TotalSeconds.ToString("F3"));
  144. output.Append(" seconds\n============================");
  145. Debug.Log(output.ToString());
  146. }
  147. [System.Diagnostics.Conditional("ProfileAstar")]
  148. public static void PrintResults () {
  149. TimeSpan endTime = DateTime.UtcNow - startTime;
  150. var output = new System.Text.StringBuilder();
  151. output.Append("============================\n\t\t\t\tProfile results:\n============================\n");
  152. int maxLength = 5;
  153. foreach (KeyValuePair<string, ProfilePoint> pair in profiles) {
  154. maxLength = Math.Max(pair.Key.Length, maxLength);
  155. }
  156. output.Append(" Name ".PadRight(maxLength)).
  157. Append("|").Append(" Total Time ".PadRight(20)).
  158. Append("|").Append(" Total Calls ".PadRight(20)).
  159. Append("|").Append(" Avg/Call ".PadRight(20));
  160. foreach (var pair in profiles) {
  161. double totalTime = pair.Value.watch.Elapsed.TotalMilliseconds;
  162. int totalCalls = pair.Value.totalCalls;
  163. if (totalCalls < 1) continue;
  164. string name = pair.Key;
  165. output.Append("\n").Append(name.PadRight(maxLength)).Append("| ");
  166. output.Append(totalTime.ToString("0.0").PadRight(20)).Append("| ");
  167. output.Append(totalCalls.ToString().PadRight(20)).Append("| ");
  168. output.Append((totalTime / totalCalls).ToString("0.000").PadRight(20));
  169. output.Append(AstarMath.FormatBytesBinary((int)pair.Value.totalBytes).PadLeft(10));
  170. /*output.Append("\nProfile ");
  171. * output.Append(pair.Key);
  172. * output.Append(" took ");
  173. * output.Append(totalTime.ToString("0"));
  174. * output.Append(" ms to complete over ");
  175. * output.Append(totalCalls);
  176. * output.Append(" iteration");
  177. * if (totalCalls != 1) output.Append("s");
  178. * output.Append(", averaging ");
  179. * output.Append((totalTime / totalCalls).ToString("0.0"));
  180. * output.Append(" ms per call");*/
  181. }
  182. output.Append("\n\n============================\n\t\tTotal runtime: ");
  183. output.Append(endTime.TotalSeconds.ToString("F3"));
  184. output.Append(" seconds\n============================");
  185. Debug.Log(output.ToString());
  186. }
  187. }
  188. }