profile.h 15 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424
  1. ////////////////////////////////////////////////////////////////////////////////
  2. //
  3. // Copyright 2016 RWS Inc, All Rights Reserved
  4. //
  5. // This program is free software; you can redistribute it and/or modify
  6. // it under the terms of version 2 of the GNU General Public License as published by
  7. // the Free Software Foundation
  8. //
  9. // This program is distributed in the hope that it will be useful,
  10. // but WITHOUT ANY WARRANTY; without even the implied warranty of
  11. // MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
  12. // GNU General Public License for more details.
  13. //
  14. // You should have received a copy of the GNU General Public License along
  15. // with this program; if not, write to the Free Software Foundation, Inc.,
  16. // 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
  17. //
  18. // COMMAND SUMMARY: - simple to use!
  19. // rspStartProfile("label"); // mark beginning of a timed code segment
  20. // rspEndProfile("label"); // mark the end of a time code segment
  21. // rspProfileOn(); // Start a profiling session
  22. // rspProfileOff(); // Suspend the Profiler
  23. // rspSetProfileOutput("filename.ext");// direct the output
  24. // #define RSP_PROFILE_ON // activate profiling in this module,
  25. // or set in project settings
  26. ///////////////////////////////////////////////////////////////////////////////
  27. //
  28. // Profile.h
  29. //
  30. // History:
  31. // 06/11/97 JRD Started.
  32. //
  33. // 06/12/97 JRD Revamped user interfaceChanged to appear as though
  34. // it's not really a class instance. Worked on timing refinement
  35. //
  36. // 06/13/97 JRD Finally got 2nd order self timing working - accurate to 60ns.
  37. // Added ability to have inside out (exclusions) loops.
  38. //
  39. // 06/14/97 JRD Added multiple report sessions, min/max reporting,
  40. // percentage of target (100%) reporting, error reporting,
  41. // and error recovery.
  42. //
  43. // 06/16/97 JRD Optimized speed over consistency.
  44. //
  45. // 07/08/97 JRD Moved destructor into header so it can be turned on and
  46. // off based on RSP_PROFILE_ON
  47. //
  48. //////////////////////////////////////////////////////////////////////////////
  49. //*********************** TUTORIAL and INFORMATION *************************
  50. //////////////////////////////////////////////////////////////////////////////
  51. //----------------------------------------------------------------------------
  52. // 1) WHY WOULD I WANT TO USE THE RSPiX PROFILER?
  53. //----------------------------------------------------------------------------
  54. // (a) - The RSPiX profiler profides fully controllable, detailed, INTERACTIVE,
  55. // multi session profiling under control of the program itself.
  56. //
  57. // (b) - This profiler has almost NO OVERHEAD. Your program will run at
  58. // FULL SPEED, and in it's native state of caching. You are measuring it's
  59. // REAL behaviour, not it's altered behavior.
  60. //
  61. // (c) - It can be used to pin down WHEN certain slow downs occur as well as
  62. // where they occur.
  63. //
  64. // (d) - It can specify the areas you wish to time with much more flexibility
  65. // than commerical profilers.
  66. //
  67. // (e) - You don't have to rebuild your whole project every time you wish
  68. // to turn profiling on or off.
  69. //
  70. // (f) - Timing more accurate than conventional profilers, so very small
  71. // non-repeating functions can be measured.
  72. //
  73. // - DISADVANTAGES OF USING THE RSPiX PROFILER -
  74. //
  75. // (a) - Since you tell it what to compare, it is better to first use a
  76. // general profiler to find the areas most suspect, than use the RSPiX
  77. // profiler to really investigate.
  78. //
  79. // (b) - You must modify your source code to debug with it. Luckily,
  80. // once in your code, it is COMPLETELY harmless when RSP_PROFILE_ON is
  81. // NOT defined. Like a TRACE or ASSERT statement, if the profiler's
  82. // turned off, your code is COMPLETELY normal, so you can leave profile
  83. // instructionsin if it is convenient.
  84. //////////////////////////////////////////////////////////////////////////////
  85. //----------------------------------------------------------------------------
  86. // 2) HOW DO I OPERATE THE RSPiX PROFILER?
  87. //----------------------------------------------------------------------------
  88. //
  89. //********************** A - Profile Pairs ***************************
  90. //
  91. // You essentially define timing pairs you wish to profile. The rest is magic.
  92. // Each profile pair you identify with a descriptive string:
  93. /*
  94. rspStartProfile("memcpy in scene");
  95. memcpy(.....);
  96. rspEndProfile("memcpy in scene");
  97. */
  98. // Take care that the text is the same in both commands, and there is a start and
  99. // an end. If you screw up, you will get a detailed error report telling you
  100. // about it.
  101. //
  102. //********************** B - Exclusion Pairs ***************************
  103. //
  104. // Putting the rspEndProfile BEFORE the rspStartProfile is 100% legal. It
  105. // allows you to provide an EXCLUSIONARY profile, i.e., everything BUT a
  106. // certain area of code:
  107. /*
  108. rspEndProfile("scene without memcpy");
  109. memcpy(.....);
  110. rspStartProfile("scene without memcpy");
  111. */
  112. //
  113. //********************** C - Disjoint pairs ***************************
  114. //
  115. // If you have more than one pair of the SAME name NOT NESTED, it will act
  116. // as a group. The total time will act as the total time of the group,
  117. // but the average time will be the average time of EACH PART of the group,
  118. // and not the combined average:
  119. /*
  120. rspStartProfile("memcpys in scene");
  121. memcpy(.....);
  122. rspEndProfile("memcpys in scene");
  123. MyCode();
  124. rspStartProfile("memcpys in scene");
  125. memcpy(.....);
  126. rspEndProfile("memcpys in scene");
  127. */
  128. //
  129. //********************** D - PERCENTAGE ***************************
  130. //
  131. // You can use any single pair in a given report at a baseline for
  132. // comparison. Just start a pair with the phrase "100%", and all other
  133. // timing pairs in that report will also give a relative percentage to
  134. // your chosen base:
  135. /*
  136. rspStartProfile("100% - the scene"); // starting the name with 100% is the key
  137. MyCode();
  138. rspStartProfile("memcpys in scene"); // will show percentage relative to scene
  139. memcpy(.....);
  140. rspEndProfile("memcpys in scene");
  141. rspEndProfile("100% - the scene");
  142. */
  143. //
  144. //********************** E - START and END TIME ***************************
  145. //
  146. // You can interactively control when timing begins in your program with
  147. // the commands:
  148. /*
  149. rspProfileOn();
  150. rspProfileOff();
  151. */
  152. // Until the first rspProfileOn(); is encountered, none of your rspStartProfile or
  153. // rspEndProfile tags will activate. Similarly, once rspProfileOff() is used,
  154. // all timing will cease and your report will be written.
  155. //
  156. //********************** F - MULTIPLE TIMING RUNS ***************************
  157. //
  158. // Perhaps the most important feature of the RSPiX profiler is that you can
  159. // do an unlimited amount of rspProfileOn() and rspProfileOff() sessions
  160. // during the SAME run of your program, and ALL will be separately tallied
  161. // and compared for you in your report. You could, for example, use a
  162. // function ey to start and stop profiling during times in a game you think
  163. // are significant.
  164. //
  165. // Independent profiles do NOT need to cover the SAME areas of your code. They
  166. // are, in fact, separate contexts, so you can freely repeat names between
  167. // them without conflict.
  168. //
  169. // When an rspEndProfile() occurs, all profile pairs in progress have their final
  170. // pass dropped from the record (no partial timing).
  171. // Similarly, if an rspStartProfile occurs in the middle of timing pairs, they
  172. // will not START timing until they have one FULL iteration. (again, no partial
  173. // timing.)
  174. //
  175. //********************** G - Deluxe Reporting ***************************
  176. //
  177. // Once you get a report, you will see all remaining features, such as
  178. // minimum and maximum speeds, and when they occurred. You will see the
  179. // relative time line of all your profiling against the program execution
  180. // time. You can get relaive percentages of timing.
  181. //
  182. //////////////////////////////////////////////////////////////////////////////
  183. //----------------------------------------------------------------------------
  184. // 3) HOW DO I "INSTALL" THE RSPiX PROFILER IN MY CURRENT PROJECT?
  185. //----------------------------------------------------------------------------
  186. // (a) - make sure "profile.cpp" is included in your project, either directly
  187. // or through the orange library.
  188. //
  189. // (b) - in any of your project files you wish to enable profiling, add an
  190. // include of "orange/debug/profil.h" or "rspix.lib". This is harmless.
  191. //
  192. // (c) - in any file you wish to activate the profiler, #define RSP_PROFILE_ON.
  193. // You may also define it as a project level macro, if you don't mind
  194. // recompiling all of your files.
  195. //
  196. // (d) - in some part of your program outside of the profiling area, you can
  197. // define where you with the profile report to go by specifying
  198. // rspSetProfileOutput("MyOutputName.ext"); Your report will go here.
  199. // Also, if you are NOT doing multi-session profiling, here is a good point
  200. // to insert your one "rspProfileOn();" command.
  201. //
  202. // (e) - put in all of the profile directives into your code, and compile
  203. // those files with RSP_PROFILE_ON defined.
  204. //////////////////////////////////////////////////////////////////////////////
  205. //----------------------------------------------------------------------------
  206. // 4) IMPORTANT PORTABILITY ISSUES
  207. //----------------------------------------------------------------------------
  208. // (a) - Currently, the RSPiX profiler makes heavy use of 64-bit integer math
  209. // because it uses a special blue function, rpsGetAppMicroseconds, which returns
  210. // the full 64-bit amount of microseconds elapsed. To do this, it uses the
  211. // non-standard S64 data type. This needs to be changed on porting.
  212. //
  213. // (b) - This program relies on FALSE being zero.
  214. //
  215. // (c) - This program uses boolean algebra for timing consistency and REQUIRES
  216. // that a boolean value of TRUE is equal to +1. If not, these sections must be
  217. // altered.
  218. //////////////////////////////////////////////////////////////////////////////
  219. #ifndef _PROFILE_H
  220. #define _PROFILE_H
  221. #include <stdlib.h>
  222. #include <string.h>
  223. #include "Blue.h"
  224. //------------------------------------
  225. // If you use global tags to do an
  226. // profile_end, you will reduce overhead!
  227. #define PF_MAX_FIELDS 20
  228. #define PF_MAX_LEN 80 // no names more than this, please!
  229. typedef enum {Inactive,Timing,DoneTiming,InError} ProfileState;
  230. #ifdef __GNUC__
  231. #define BIGS64(x) S64(x##ll)
  232. #else
  233. #define BIGS64(x) S64(x)
  234. #endif
  235. class RProfileNode
  236. {
  237. public:
  238. //----------------------------
  239. void Init()
  240. {
  241. m_szFieldName[0] = 0;
  242. m_lNumCalls = m_lTotTime = m_lLastTime = m_lMaxTime = m_lWhenMin = m_lWhenMax = 0;
  243. m_lMinTime = BIGS64(999999999999);
  244. m_eState = Inactive;
  245. m_sInError = FALSE;
  246. }
  247. RProfileNode()
  248. {
  249. Init();
  250. }
  251. ~RProfileNode(){};
  252. //----------------------------
  253. char m_szFieldName[PF_MAX_LEN];
  254. S64 m_lNumCalls;
  255. S64 m_lTotTime;
  256. S64 m_lLastTime;
  257. S64 m_lMinTime;
  258. S64 m_lWhenMin; // relative to begin
  259. S64 m_lMaxTime;
  260. S64 m_lWhenMax; // relative to begin
  261. ProfileState m_eState; // parenthesis verification!
  262. #define PF_START_ERR 1
  263. #define PF_END_ERR 2
  264. short m_sInError; // parenthesis mismatch!
  265. };
  266. class RProfile
  267. {
  268. public:
  269. void StartProfile(char* pszFieldName);
  270. void EndProfile(char* pszFieldName);
  271. //----------------------------
  272. void SetOutput(char *pszOutput)
  273. {
  274. if (pszOutput) strcpy(m_szOutputFile,pszOutput);
  275. }
  276. void ProfilingOn()
  277. {
  278. // Can't try to turn it back on even if there's been a problem!
  279. // (further profiles can be valid)
  280. m_sInternalError = m_sCommandError = FALSE;
  281. m_sActive = TRUE;
  282. // Reset all profiles in progress:
  283. m_sNumTracked = 0;
  284. // Reset th overhead as well:
  285. m_lCount = m_lTotTime = 0;
  286. m_lFastTimeIn = m_lFastTimeOut = 0;
  287. m_sLastUnaccounted = 0;
  288. m_sMaxDepth = m_sCurDepth = 0;
  289. // Get a new base time!
  290. m_lBeginTime = rspGetAppMicroseconds();
  291. }
  292. // Each time you turn off profiling, I'll do a report apend:
  293. //
  294. void ProfilingOff()
  295. {
  296. // don't allow double reports for double stops
  297. if (m_sActive == FALSE) return;
  298. m_sActive = FALSE;
  299. if (m_sNumTracked) Report(); // Give the report!
  300. // Deactivate all ranges (shouldn't really be needed!)
  301. /*
  302. for (short i=0; i < m_sNumTracked;i++)
  303. {
  304. if (m_aList[i].m_eState != InError) m_aList[i].m_eState = Inactive;
  305. }
  306. */
  307. }
  308. //S64 DetermineTimeError();
  309. void Report(); // tell it all!
  310. //----------------------------
  311. // THIS IS IN THE HEADER SO IT CAN BE AFFECTED BY RSP_PROFILE_ON
  312. ~RProfile()
  313. {
  314. #ifdef RSP_PROFILE_ON
  315. if (m_sActive) Report(); // No closing profile
  316. m_lDeceasedTime = rspGetAppMicroseconds(); // the Last element
  317. Report(); // Give the report!
  318. #endif
  319. };
  320. RProfile(); // in cpp file
  321. //----------------------------
  322. S64 m_lCount; // to determine my own overhead!
  323. S64 m_lTotTime; // Total overhead used by profiling!
  324. S64 m_lInitTime; // start of program
  325. S64 m_lDeceasedTime; // end of program
  326. S64 m_lBeginTime; // when user kicks off profiling
  327. S64 m_lFirstTime; // first time a profile range is entered in active mode
  328. //===== Let's try to max out a theme here:
  329. S64 m_lFastTimeIn;
  330. S64 m_lFastTimeOut;
  331. //----------------------------
  332. short m_sLastUnaccounted;// Used for one frame lag timing of unknown overhead...
  333. short m_sNumTracked; // how many in count?
  334. short m_sCommandError; // mismatched parenthesis
  335. short m_sMaxDepth; // Used for third order error estimation
  336. short m_sCurDepth; // Used for third order error estimation
  337. short m_sActive; // suspend / resume profiling...
  338. short m_sInternalError; // Usually memory limits...
  339. char m_szOutputFile[256];
  340. RProfileNode m_aList[PF_MAX_FIELDS];
  341. };
  342. /////////////////////////////////////////////////////////////////
  343. // The new profiler has one global established instance:
  344. /////////////////////////////////////////////////////////////////
  345. /////////////////////////////////////////////////////////////////
  346. // Set up the user interface convention:
  347. /////////////////////////////////////////////////////////////////
  348. extern RProfile rspProfileInstance; // The one global instance
  349. inline void rspProfileOptimizeOut(char* a) {} // used to trick the compiler
  350. inline void rspProfileOptimizeOut() {} // used to trick the compiler
  351. #ifdef RSP_PROFILE_ON
  352. /////////////////////////////////////////////////////////////////
  353. #define rspStartProfile(a) rspProfileInstance.StartProfile(a)
  354. #define rspEndProfile(a) rspProfileInstance.EndProfile(a)
  355. #define rspProfileOn() rspProfileInstance.ProfilingOn()
  356. #define rspProfileOff() rspProfileInstance.ProfilingOff()
  357. #define rspSetProfileOutput(a) rspProfileInstance.SetOutput(a)
  358. /////////////////////////////////////////////////////////////////
  359. #else
  360. /////////////////////////////////////////////////////////////////
  361. #define rspStartProfile(a) 1 ? (void)0 : rspProfileOptimizeOut(a)
  362. #define rspEndProfile(a) 1 ? (void)0 : rspProfileOptimizeOut(a)
  363. #define rspProfileOn() 1 ? (void)0 : rspProfileOptimizeOut()
  364. #define rspProfileOff() 1 ? (void)0 : rspProfileOptimizeOut()
  365. #define rspSetProfileOutput(a) 1 ? (void)0 : rspProfileOptimizeOut(a)
  366. /////////////////////////////////////////////////////////////////
  367. #endif
  368. //------------------------------------
  369. #endif