AstarProfiler.cs 7.7 KB

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