Profiler.cpp 11 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397
  1. // SPDX-FileCopyrightText: 2021 Jorrit Rouwe
  2. // SPDX-License-Identifier: MIT
  3. #include <Jolt.h>
  4. #include <Core/Profiler.h>
  5. #include <Core/Color.h>
  6. #include <Core/StringTools.h>
  7. #include <fstream>
  8. #ifdef JPH_PROFILE_ENABLED
  9. namespace JPH {
  10. //////////////////////////////////////////////////////////////////////////////////////////
  11. // Profiler
  12. //////////////////////////////////////////////////////////////////////////////////////////
  13. Profiler Profiler::sInstance;
  14. thread_local ProfileThread *ProfileThread::sInstance = nullptr;
  15. bool ProfileMeasurement::sOutOfSamplesReported = false;
  16. void Profiler::NextFrame()
  17. {
  18. lock_guard lock(mLock);
  19. if (mDump)
  20. {
  21. DumpInternal();
  22. mDump = false;
  23. }
  24. for (ProfileThread *t : mThreads)
  25. t->mCurrentSample = 0;
  26. }
  27. void Profiler::Dump(string inTag)
  28. {
  29. mDump = true;
  30. mDumpTag = inTag;
  31. }
  32. void Profiler::AddThread(ProfileThread *inThread)
  33. {
  34. lock_guard lock(mLock);
  35. mThreads.push_back(inThread);
  36. }
  37. void Profiler::RemoveThread(ProfileThread *inThread)
  38. {
  39. lock_guard lock(mLock);
  40. vector<ProfileThread *>::iterator i = find(mThreads.begin(), mThreads.end(), inThread);
  41. JPH_ASSERT(i != mThreads.end());
  42. mThreads.erase(i);
  43. }
  44. void Profiler::sAggregate(int inDepth, uint32 inColor, ProfileSample *&ioSample, const ProfileSample *inEnd, Aggregators &ioAggregators, KeyToAggregator &ioKeyToAggregator)
  45. {
  46. // Store depth
  47. ioSample->mDepth = uint8(min(255, inDepth));
  48. // Update color
  49. if (ioSample->mColor == 0)
  50. ioSample->mColor = inColor;
  51. else
  52. inColor = ioSample->mColor;
  53. // Start accumulating totals
  54. uint64 cycles_this_with_children = ioSample->mEndCycle - ioSample->mStartCycle;
  55. uint64 cycles_in_children = 0;
  56. // Loop over following samples until we find a sample that starts on or after our end
  57. ProfileSample *sample;
  58. for (sample = ioSample + 1; sample < inEnd && sample->mStartCycle < ioSample->mEndCycle; ++sample)
  59. {
  60. JPH_ASSERT(sample[-1].mStartCycle <= sample->mStartCycle);
  61. JPH_ASSERT(sample->mStartCycle >= ioSample->mStartCycle);
  62. JPH_ASSERT(sample->mEndCycle <= ioSample->mEndCycle);
  63. // This is a direct child of us, accumulate time
  64. cycles_in_children += sample->mEndCycle - sample->mStartCycle;
  65. // Recurse and skip over the children of this child
  66. sAggregate(inDepth + 1, inColor, sample, inEnd, ioAggregators, ioKeyToAggregator);
  67. }
  68. // Find the aggregator for this name / filename pair
  69. Aggregator *aggregator;
  70. KeyToAggregator::iterator aggregator_idx = ioKeyToAggregator.find(ioSample->mName);
  71. if (aggregator_idx == ioKeyToAggregator.end())
  72. {
  73. // Not found, add to map and insert in array
  74. ioKeyToAggregator.insert(KeyToAggregator::value_type(ioSample->mName, ioAggregators.size()));
  75. ioAggregators.emplace_back(ioSample->mName);
  76. aggregator = &ioAggregators.back();
  77. }
  78. else
  79. {
  80. // Found
  81. aggregator = &ioAggregators[aggregator_idx->second];
  82. }
  83. // Add the measurement to the aggregator
  84. aggregator->AccumulateMeasurement(cycles_this_with_children, cycles_in_children);
  85. // Update ioSample to the last child of ioSample
  86. JPH_ASSERT(sample[-1].mStartCycle < ioSample->mEndCycle);
  87. JPH_ASSERT(sample >= inEnd || sample->mStartCycle >= ioSample->mEndCycle);
  88. ioSample = sample - 1;
  89. }
  90. void Profiler::DumpInternal()
  91. {
  92. // Freeze data from threads
  93. // Note that this is not completely thread safe: As a profile sample is added mCurrentSample is incremented
  94. // but the data is not written until the sample finishes. So if we dump the profile information while
  95. // some other thread is running, we may get some garbage information from the previous frame
  96. Threads threads;
  97. for (ProfileThread *t : mThreads)
  98. threads.push_back({ t->mThreadName, t->mSamples, t->mSamples + t->mCurrentSample });
  99. // Shift all samples so that the first sample is at zero
  100. uint64 min_cycle = 0xffffffffffffffffUL;
  101. for (const ThreadSamples &t : threads)
  102. if (t.mSamplesBegin < t.mSamplesEnd)
  103. min_cycle = min(min_cycle, t.mSamplesBegin[0].mStartCycle);
  104. for (const ThreadSamples &t : threads)
  105. for (ProfileSample *s = t.mSamplesBegin, *end = t.mSamplesEnd; s < end; ++s)
  106. {
  107. s->mStartCycle -= min_cycle;
  108. s->mEndCycle -= min_cycle;
  109. }
  110. // Determine tag of this profile
  111. string tag;
  112. if (mDumpTag.empty())
  113. {
  114. // Next sequence number
  115. static int number = 0;
  116. ++number;
  117. tag = ConvertToString(number);
  118. }
  119. else
  120. {
  121. // Take provided tag
  122. tag = mDumpTag;
  123. mDumpTag.clear();
  124. }
  125. // Aggregate data across threads
  126. Aggregators aggregators;
  127. KeyToAggregator key_to_aggregators;
  128. for (const ThreadSamples &t : threads)
  129. for (ProfileSample *s = t.mSamplesBegin, *end = t.mSamplesEnd; s < end; ++s)
  130. sAggregate(0, Color::sGetDistinctColor(0).GetUInt32(), s, end, aggregators, key_to_aggregators);
  131. // Dump as list
  132. DumpList(tag, aggregators);
  133. // Dump as chart
  134. DumpChart(tag, threads, key_to_aggregators, aggregators);
  135. }
  136. static string sHTMLEncode(string inString)
  137. {
  138. string str = inString;
  139. StringReplace(str, "<", "&lt;");
  140. StringReplace(str, ">", "&gt;");
  141. return str;
  142. }
  143. void Profiler::DumpList(string inTag, const Aggregators &inAggregators)
  144. {
  145. // Open file
  146. ofstream f;
  147. f.open(StringFormat("profile_list_%s.html", inTag.c_str()).c_str(), ofstream::out | ofstream::trunc);
  148. if (!f.is_open())
  149. return;
  150. // Write header
  151. f << R"(<!DOCTYPE html>
  152. <html>
  153. <head>
  154. <title>Profile List</title>
  155. <link rel="stylesheet" href="WebIncludes/semantic.min.css">
  156. <script type="text/javascript" src="WebIncludes/jquery-3.2.1.min.js"></script>
  157. <script type="text/javascript" src="WebIncludes/semantic.min.js"></script>
  158. <script type="text/javascript" src="WebIncludes/tablesort.js"></script>
  159. <script type="text/javascript">$(document).ready(function() { $('table').tablesort({ compare: function(a, b) { return isNaN(a) || isNaN(b)? a.localeCompare(b) : Number(a) - Number(b); } }); });</script>
  160. </head>
  161. <body class="minimal pushable">
  162. <table id="profile" class="ui sortable celled striped table">
  163. <thead>
  164. <tr>
  165. <th>Description</th>
  166. <th class="sorted descending">Total time with children (%)</th>
  167. <th>Total time (%)</th>
  168. <th>Calls</th>
  169. <th>&micro;s / call with children</th>
  170. <th>&micro;s / call</th>
  171. <th>Min. &micro;s / call</th>
  172. <th>Max. &micro;s / call</th>
  173. </tr>
  174. </thead>
  175. <tbody style="text-align: right;">
  176. )";
  177. // Get total time
  178. uint64 total_time = 0;
  179. for (const Aggregator &item : inAggregators)
  180. total_time += item.mTotalCyclesInCallWithChildren - item.mTotalCyclesInChildren;
  181. // Get cycles per second
  182. uint64 cycles_per_second = GetProcessorTicksPerSecond();
  183. // Sort the list
  184. Aggregators aggregators = inAggregators;
  185. sort(aggregators.begin(), aggregators.end());
  186. // Write all aggregators
  187. for (const Aggregator &item : aggregators)
  188. {
  189. uint64 cycles_in_call_no_children = item.mTotalCyclesInCallWithChildren - item.mTotalCyclesInChildren;
  190. char str[2048];
  191. snprintf(str, sizeof(str), R"(<tr>
  192. <td style="text-align: left;">%s</td>
  193. <td>%.1f</td>
  194. <td>%.1f</td>
  195. <td>%u</td>
  196. <td>%.2f</td>
  197. <td>%.2f</td>
  198. <td>%.2f</td>
  199. <td>%.2f</td>
  200. </tr>)",
  201. sHTMLEncode(item.mName).c_str(), // Description
  202. 100.0 * item.mTotalCyclesInCallWithChildren / total_time, // Total time with children
  203. 100.0 * cycles_in_call_no_children / total_time, // Total time no children
  204. item.mCallCounter, // Calls
  205. 1000000.0 * item.mTotalCyclesInCallWithChildren / cycles_per_second / item.mCallCounter, // us / call with children
  206. 1000000.0 * cycles_in_call_no_children / cycles_per_second / item.mCallCounter, // us / call no children
  207. 1000000.0 * item.mMinCyclesInCallWithChildren / cycles_per_second, // Min. us / call with children
  208. 1000000.0 * item.mMaxCyclesInCallWithChildren / cycles_per_second); // Max. us / call with children
  209. f << str;
  210. }
  211. // End table
  212. f << R"(</tbody></table></body></html>)";
  213. }
  214. void Profiler::DumpChart(string inTag, const Threads &inThreads, const KeyToAggregator &inKeyToAggregators, const Aggregators &inAggregators)
  215. {
  216. // Open file
  217. ofstream f;
  218. f.open(StringFormat("profile_chart_%s.html", inTag.c_str()).c_str(), ofstream::out | ofstream::trunc);
  219. if (!f.is_open())
  220. return;
  221. // Write header
  222. f << R"(<!DOCTYPE html>
  223. <html>
  224. <head>
  225. <title>Profile Chart</title>
  226. <link rel="stylesheet" href="WebIncludes/profile_chart.css">
  227. <script type="text/javascript" src="WebIncludes/profile_chart.js"></script>
  228. </head>
  229. <body onload="startChart();">
  230. <script type="text/javascript">
  231. )";
  232. // Get cycles per second
  233. uint64 cycles_per_second = GetProcessorTicksPerSecond();
  234. f << "var cycles_per_second = " << cycles_per_second << ";\n";
  235. // Dump samples
  236. f << "var threads = [\n";
  237. bool first_thread = true;
  238. for (const ThreadSamples &t : inThreads)
  239. {
  240. if (!first_thread)
  241. f << ",\n";
  242. first_thread = false;
  243. f << "{\nthread_name: \"" << t.mThreadName << "\",\naggregator: [";
  244. bool first = true;
  245. for (const ProfileSample *s = t.mSamplesBegin, *end = t.mSamplesEnd; s < end; ++s)
  246. {
  247. if (!first)
  248. f << ",";
  249. first = false;
  250. f << inKeyToAggregators.find(s->mName)->second;
  251. }
  252. f << "],\ncolor: [";
  253. first = true;
  254. for (const ProfileSample *s = t.mSamplesBegin, *end = t.mSamplesEnd; s < end; ++s)
  255. {
  256. if (!first)
  257. f << ",";
  258. first = false;
  259. Color c(s->mColor);
  260. f << StringFormat("\"#%02x%02x%02x\"", c.r, c.g, c.b);
  261. }
  262. f << "],\nstart: [";
  263. first = true;
  264. for (const ProfileSample *s = t.mSamplesBegin, *end = t.mSamplesEnd; s < end; ++s)
  265. {
  266. if (!first)
  267. f << ",";
  268. first = false;
  269. f << s->mStartCycle;
  270. }
  271. f << "],\ncycles: [";
  272. first = true;
  273. for (const ProfileSample *s = t.mSamplesBegin, *end = t.mSamplesEnd; s < end; ++s)
  274. {
  275. if (!first)
  276. f << ",";
  277. first = false;
  278. f << s->mEndCycle - s->mStartCycle;
  279. }
  280. f << "],\ndepth: [";
  281. first = true;
  282. for (const ProfileSample *s = t.mSamplesBegin, *end = t.mSamplesEnd; s < end; ++s)
  283. {
  284. if (!first)
  285. f << ",";
  286. first = false;
  287. f << int(s->mDepth);
  288. }
  289. f << "]\n}";
  290. }
  291. // Dump aggregated data
  292. f << "];\nvar aggregated = {\nname: [";
  293. bool first = true;
  294. for (const Aggregator &a : inAggregators)
  295. {
  296. if (!first)
  297. f << ",";
  298. first = false;
  299. string name = "\"" + sHTMLEncode(a.mName) + "\"";
  300. f << name;
  301. }
  302. f << "],\ncalls: [";
  303. first = true;
  304. for (const Aggregator &a : inAggregators)
  305. {
  306. if (!first)
  307. f << ",";
  308. first = false;
  309. f << a.mCallCounter;
  310. }
  311. f << "],\nmin_cycles: [";
  312. first = true;
  313. for (const Aggregator &a : inAggregators)
  314. {
  315. if (!first)
  316. f << ",";
  317. first = false;
  318. f << a.mMinCyclesInCallWithChildren;
  319. }
  320. f << "],\nmax_cycles: [";
  321. first = true;
  322. for (const Aggregator &a : inAggregators)
  323. {
  324. if (!first)
  325. f << ",";
  326. first = false;
  327. f << a.mMaxCyclesInCallWithChildren;
  328. }
  329. f << "],\ncycles_per_frame: [";
  330. first = true;
  331. for (const Aggregator &a : inAggregators)
  332. {
  333. if (!first)
  334. f << ",";
  335. first = false;
  336. f << a.mTotalCyclesInCallWithChildren;
  337. }
  338. // Write footer
  339. f << R"(]};
  340. </script>
  341. <canvas id="canvas"></canvas>
  342. <div id="tooltip"></div>
  343. </tbody></table></body></html>)";
  344. }
  345. } // JPH
  346. #endif // JPH_PROFILE_ENABLED