Nie możesz wybrać więcej, niż 25 tematów Tematy muszą się zaczynać od litery lub cyfry, mogą zawierać myślniki ('-') i mogą mieć do 35 znaków.
 
 
 

569 wiersze
16 KiB

  1. /*
  2. ***************************************************************************************************
  3. **
  4. ** profile.cpp
  5. **
  6. ** Real-Time Hierarchical Profiling for Game Programming Gems 3
  7. **
  8. ** by Greg Hjelstrom & Byon Garrabrant
  9. **
  10. ***************************************************************************************************/
  11. // Credits: The Clock class was inspired by the Timer classes in
  12. // Ogre (www.ogre3d.org).
  13. #include "btQuickprof.h"
  14. #ifndef BT_NO_PROFILE
  15. static btClock gProfileClock;
  16. #ifdef __CELLOS_LV2__
  17. #include <sys/sys_time.h>
  18. #include <sys/time_util.h>
  19. #include <stdio.h>
  20. #endif
  21. #if defined (SUNOS) || defined (__SUNOS__)
  22. #include <stdio.h>
  23. #endif
  24. #if defined(WIN32) || defined(_WIN32)
  25. #define BT_USE_WINDOWS_TIMERS
  26. #define WIN32_LEAN_AND_MEAN
  27. #define NOWINRES
  28. #define NOMCX
  29. #define NOIME
  30. #ifdef _XBOX
  31. #include <Xtl.h>
  32. #else //_XBOX
  33. #include <windows.h>
  34. #endif //_XBOX
  35. #include <time.h>
  36. #else //_WIN32
  37. #include <sys/time.h>
  38. #endif //_WIN32
  39. #define mymin(a,b) (a > b ? a : b)
  40. struct btClockData
  41. {
  42. #ifdef BT_USE_WINDOWS_TIMERS
  43. LARGE_INTEGER mClockFrequency;
  44. DWORD mStartTick;
  45. LONGLONG mPrevElapsedTime;
  46. LARGE_INTEGER mStartTime;
  47. #else
  48. #ifdef __CELLOS_LV2__
  49. uint64_t mStartTime;
  50. #else
  51. struct timeval mStartTime;
  52. #endif
  53. #endif //__CELLOS_LV2__
  54. };
  55. ///The btClock is a portable basic clock that measures accurate time in seconds, use for profiling.
  56. btClock::btClock()
  57. {
  58. m_data = new btClockData;
  59. #ifdef BT_USE_WINDOWS_TIMERS
  60. QueryPerformanceFrequency(&m_data->mClockFrequency);
  61. #endif
  62. reset();
  63. }
  64. btClock::~btClock()
  65. {
  66. delete m_data;
  67. }
  68. btClock::btClock(const btClock& other)
  69. {
  70. m_data = new btClockData;
  71. *m_data = *other.m_data;
  72. }
  73. btClock& btClock::operator=(const btClock& other)
  74. {
  75. *m_data = *other.m_data;
  76. return *this;
  77. }
  78. /// Resets the initial reference time.
  79. void btClock::reset()
  80. {
  81. #ifdef BT_USE_WINDOWS_TIMERS
  82. QueryPerformanceCounter(&m_data->mStartTime);
  83. m_data->mStartTick = GetTickCount();
  84. m_data->mPrevElapsedTime = 0;
  85. #else
  86. #ifdef __CELLOS_LV2__
  87. typedef uint64_t ClockSize;
  88. ClockSize newTime;
  89. //__asm __volatile__( "mftb %0" : "=r" (newTime) : : "memory");
  90. SYS_TIMEBASE_GET( newTime );
  91. m_data->mStartTime = newTime;
  92. #else
  93. gettimeofday(&m_data->mStartTime, 0);
  94. #endif
  95. #endif
  96. }
  97. /// Returns the time in ms since the last call to reset or since
  98. /// the btClock was created.
  99. unsigned long int btClock::getTimeMilliseconds()
  100. {
  101. #ifdef BT_USE_WINDOWS_TIMERS
  102. LARGE_INTEGER currentTime;
  103. QueryPerformanceCounter(&currentTime);
  104. LONGLONG elapsedTime = currentTime.QuadPart -
  105. m_data->mStartTime.QuadPart;
  106. // Compute the number of millisecond ticks elapsed.
  107. unsigned long msecTicks = (unsigned long)(1000 * elapsedTime /
  108. m_data->mClockFrequency.QuadPart);
  109. // Check for unexpected leaps in the Win32 performance counter.
  110. // (This is caused by unexpected data across the PCI to ISA
  111. // bridge, aka south bridge. See Microsoft KB274323.)
  112. unsigned long elapsedTicks = GetTickCount() - m_data->mStartTick;
  113. signed long msecOff = (signed long)(msecTicks - elapsedTicks);
  114. if (msecOff < -100 || msecOff > 100)
  115. {
  116. // Adjust the starting time forwards.
  117. LONGLONG msecAdjustment = mymin(msecOff *
  118. m_data->mClockFrequency.QuadPart / 1000, elapsedTime -
  119. m_data->mPrevElapsedTime);
  120. m_data->mStartTime.QuadPart += msecAdjustment;
  121. elapsedTime -= msecAdjustment;
  122. // Recompute the number of millisecond ticks elapsed.
  123. msecTicks = (unsigned long)(1000 * elapsedTime /
  124. m_data->mClockFrequency.QuadPart);
  125. }
  126. // Store the current elapsed time for adjustments next time.
  127. m_data->mPrevElapsedTime = elapsedTime;
  128. return msecTicks;
  129. #else
  130. #ifdef __CELLOS_LV2__
  131. uint64_t freq=sys_time_get_timebase_frequency();
  132. double dFreq=((double) freq) / 1000.0;
  133. typedef uint64_t ClockSize;
  134. ClockSize newTime;
  135. SYS_TIMEBASE_GET( newTime );
  136. //__asm __volatile__( "mftb %0" : "=r" (newTime) : : "memory");
  137. return (unsigned long int)((double(newTime-m_data->mStartTime)) / dFreq);
  138. #else
  139. struct timeval currentTime;
  140. gettimeofday(&currentTime, 0);
  141. return (currentTime.tv_sec - m_data->mStartTime.tv_sec) * 1000 +
  142. (currentTime.tv_usec - m_data->mStartTime.tv_usec) / 1000;
  143. #endif //__CELLOS_LV2__
  144. #endif
  145. }
  146. /// Returns the time in us since the last call to reset or since
  147. /// the Clock was created.
  148. unsigned long int btClock::getTimeMicroseconds()
  149. {
  150. #ifdef BT_USE_WINDOWS_TIMERS
  151. LARGE_INTEGER currentTime;
  152. QueryPerformanceCounter(&currentTime);
  153. LONGLONG elapsedTime = currentTime.QuadPart -
  154. m_data->mStartTime.QuadPart;
  155. // Compute the number of millisecond ticks elapsed.
  156. unsigned long msecTicks = (unsigned long)(1000 * elapsedTime /
  157. m_data->mClockFrequency.QuadPart);
  158. // Check for unexpected leaps in the Win32 performance counter.
  159. // (This is caused by unexpected data across the PCI to ISA
  160. // bridge, aka south bridge. See Microsoft KB274323.)
  161. unsigned long elapsedTicks = GetTickCount() - m_data->mStartTick;
  162. signed long msecOff = (signed long)(msecTicks - elapsedTicks);
  163. if (msecOff < -100 || msecOff > 100)
  164. {
  165. // Adjust the starting time forwards.
  166. LONGLONG msecAdjustment = mymin(msecOff *
  167. m_data->mClockFrequency.QuadPart / 1000, elapsedTime -
  168. m_data->mPrevElapsedTime);
  169. m_data->mStartTime.QuadPart += msecAdjustment;
  170. elapsedTime -= msecAdjustment;
  171. }
  172. // Store the current elapsed time for adjustments next time.
  173. m_data->mPrevElapsedTime = elapsedTime;
  174. // Convert to microseconds.
  175. unsigned long usecTicks = (unsigned long)(1000000 * elapsedTime /
  176. m_data->mClockFrequency.QuadPart);
  177. return usecTicks;
  178. #else
  179. #ifdef __CELLOS_LV2__
  180. uint64_t freq=sys_time_get_timebase_frequency();
  181. double dFreq=((double) freq)/ 1000000.0;
  182. typedef uint64_t ClockSize;
  183. ClockSize newTime;
  184. //__asm __volatile__( "mftb %0" : "=r" (newTime) : : "memory");
  185. SYS_TIMEBASE_GET( newTime );
  186. return (unsigned long int)((double(newTime-m_data->mStartTime)) / dFreq);
  187. #else
  188. struct timeval currentTime;
  189. gettimeofday(&currentTime, 0);
  190. return (currentTime.tv_sec - m_data->mStartTime.tv_sec) * 1000000 +
  191. (currentTime.tv_usec - m_data->mStartTime.tv_usec);
  192. #endif//__CELLOS_LV2__
  193. #endif
  194. }
  195. inline void Profile_Get_Ticks(unsigned long int * ticks)
  196. {
  197. *ticks = gProfileClock.getTimeMicroseconds();
  198. }
  199. inline float Profile_Get_Tick_Rate(void)
  200. {
  201. // return 1000000.f;
  202. return 1000.f;
  203. }
  204. /***************************************************************************************************
  205. **
  206. ** CProfileNode
  207. **
  208. ***************************************************************************************************/
  209. /***********************************************************************************************
  210. * INPUT: *
  211. * name - pointer to a static string which is the name of this profile node *
  212. * parent - parent pointer *
  213. * *
  214. * WARNINGS: *
  215. * The name is assumed to be a static pointer, only the pointer is stored and compared for *
  216. * efficiency reasons. *
  217. *=============================================================================================*/
  218. CProfileNode::CProfileNode( const char * name, CProfileNode * parent ) :
  219. Name( name ),
  220. TotalCalls( 0 ),
  221. TotalTime( 0 ),
  222. StartTime( 0 ),
  223. RecursionCounter( 0 ),
  224. Parent( parent ),
  225. Child( NULL ),
  226. Sibling( NULL ),
  227. m_userPtr(0)
  228. {
  229. Reset();
  230. }
  231. void CProfileNode::CleanupMemory()
  232. {
  233. delete ( Child);
  234. Child = NULL;
  235. delete ( Sibling);
  236. Sibling = NULL;
  237. }
  238. CProfileNode::~CProfileNode( void )
  239. {
  240. delete ( Child);
  241. delete ( Sibling);
  242. }
  243. /***********************************************************************************************
  244. * INPUT: *
  245. * name - static string pointer to the name of the node we are searching for *
  246. * *
  247. * WARNINGS: *
  248. * All profile names are assumed to be static strings so this function uses pointer compares *
  249. * to find the named node. *
  250. *=============================================================================================*/
  251. CProfileNode * CProfileNode::Get_Sub_Node( const char * name )
  252. {
  253. // Try to find this sub node
  254. CProfileNode * child = Child;
  255. while ( child ) {
  256. if ( child->Name == name ) {
  257. return child;
  258. }
  259. child = child->Sibling;
  260. }
  261. // We didn't find it, so add it
  262. CProfileNode * node = new CProfileNode( name, this );
  263. node->Sibling = Child;
  264. Child = node;
  265. return node;
  266. }
  267. void CProfileNode::Reset( void )
  268. {
  269. TotalCalls = 0;
  270. TotalTime = 0.0f;
  271. if ( Child ) {
  272. Child->Reset();
  273. }
  274. if ( Sibling ) {
  275. Sibling->Reset();
  276. }
  277. }
  278. void CProfileNode::Call( void )
  279. {
  280. TotalCalls++;
  281. if (RecursionCounter++ == 0) {
  282. Profile_Get_Ticks(&StartTime);
  283. }
  284. }
  285. bool CProfileNode::Return( void )
  286. {
  287. if ( --RecursionCounter == 0 && TotalCalls != 0 ) {
  288. unsigned long int time;
  289. Profile_Get_Ticks(&time);
  290. time-=StartTime;
  291. TotalTime += (float)time / Profile_Get_Tick_Rate();
  292. }
  293. return ( RecursionCounter == 0 );
  294. }
  295. /***************************************************************************************************
  296. **
  297. ** CProfileIterator
  298. **
  299. ***************************************************************************************************/
  300. CProfileIterator::CProfileIterator( CProfileNode * start )
  301. {
  302. CurrentParent = start;
  303. CurrentChild = CurrentParent->Get_Child();
  304. }
  305. void CProfileIterator::First(void)
  306. {
  307. CurrentChild = CurrentParent->Get_Child();
  308. }
  309. void CProfileIterator::Next(void)
  310. {
  311. CurrentChild = CurrentChild->Get_Sibling();
  312. }
  313. bool CProfileIterator::Is_Done(void)
  314. {
  315. return CurrentChild == NULL;
  316. }
  317. void CProfileIterator::Enter_Child( int index )
  318. {
  319. CurrentChild = CurrentParent->Get_Child();
  320. while ( (CurrentChild != NULL) && (index != 0) ) {
  321. index--;
  322. CurrentChild = CurrentChild->Get_Sibling();
  323. }
  324. if ( CurrentChild != NULL ) {
  325. CurrentParent = CurrentChild;
  326. CurrentChild = CurrentParent->Get_Child();
  327. }
  328. }
  329. void CProfileIterator::Enter_Parent( void )
  330. {
  331. if ( CurrentParent->Get_Parent() != NULL ) {
  332. CurrentParent = CurrentParent->Get_Parent();
  333. }
  334. CurrentChild = CurrentParent->Get_Child();
  335. }
  336. /***************************************************************************************************
  337. **
  338. ** CProfileManager
  339. **
  340. ***************************************************************************************************/
  341. CProfileNode CProfileManager::Root( "Root", NULL );
  342. CProfileNode * CProfileManager::CurrentNode = &CProfileManager::Root;
  343. int CProfileManager::FrameCounter = 0;
  344. unsigned long int CProfileManager::ResetTime = 0;
  345. /***********************************************************************************************
  346. * CProfileManager::Start_Profile -- Begin a named profile *
  347. * *
  348. * Steps one level deeper into the tree, if a child already exists with the specified name *
  349. * then it accumulates the profiling; otherwise a new child node is added to the profile tree. *
  350. * *
  351. * INPUT: *
  352. * name - name of this profiling record *
  353. * *
  354. * WARNINGS: *
  355. * The string used is assumed to be a static string; pointer compares are used throughout *
  356. * the profiling code for efficiency. *
  357. *=============================================================================================*/
  358. void CProfileManager::Start_Profile( const char * name )
  359. {
  360. if (name != CurrentNode->Get_Name()) {
  361. CurrentNode = CurrentNode->Get_Sub_Node( name );
  362. }
  363. CurrentNode->Call();
  364. }
  365. /***********************************************************************************************
  366. * CProfileManager::Stop_Profile -- Stop timing and record the results. *
  367. *=============================================================================================*/
  368. void CProfileManager::Stop_Profile( void )
  369. {
  370. // Return will indicate whether we should back up to our parent (we may
  371. // be profiling a recursive function)
  372. if (CurrentNode->Return()) {
  373. CurrentNode = CurrentNode->Get_Parent();
  374. }
  375. }
  376. /***********************************************************************************************
  377. * CProfileManager::Reset -- Reset the contents of the profiling system *
  378. * *
  379. * This resets everything except for the tree structure. All of the timing data is reset. *
  380. *=============================================================================================*/
  381. void CProfileManager::Reset( void )
  382. {
  383. gProfileClock.reset();
  384. Root.Reset();
  385. Root.Call();
  386. FrameCounter = 0;
  387. Profile_Get_Ticks(&ResetTime);
  388. }
  389. /***********************************************************************************************
  390. * CProfileManager::Increment_Frame_Counter -- Increment the frame counter *
  391. *=============================================================================================*/
  392. void CProfileManager::Increment_Frame_Counter( void )
  393. {
  394. FrameCounter++;
  395. }
  396. /***********************************************************************************************
  397. * CProfileManager::Get_Time_Since_Reset -- returns the elapsed time since last reset *
  398. *=============================================================================================*/
  399. float CProfileManager::Get_Time_Since_Reset( void )
  400. {
  401. unsigned long int time;
  402. Profile_Get_Ticks(&time);
  403. time -= ResetTime;
  404. return (float)time / Profile_Get_Tick_Rate();
  405. }
  406. #include <stdio.h>
  407. void CProfileManager::dumpRecursive(CProfileIterator* profileIterator, int spacing)
  408. {
  409. profileIterator->First();
  410. if (profileIterator->Is_Done())
  411. return;
  412. float accumulated_time=0,parent_time = profileIterator->Is_Root() ? CProfileManager::Get_Time_Since_Reset() : profileIterator->Get_Current_Parent_Total_Time();
  413. int i;
  414. int frames_since_reset = CProfileManager::Get_Frame_Count_Since_Reset();
  415. for (i=0;i<spacing;i++) printf(".");
  416. printf("----------------------------------\n");
  417. for (i=0;i<spacing;i++) printf(".");
  418. printf("Profiling: %s (total running time: %.3f ms) ---\n", profileIterator->Get_Current_Parent_Name(), parent_time );
  419. float totalTime = 0.f;
  420. int numChildren = 0;
  421. for (i = 0; !profileIterator->Is_Done(); i++,profileIterator->Next())
  422. {
  423. numChildren++;
  424. float current_total_time = profileIterator->Get_Current_Total_Time();
  425. accumulated_time += current_total_time;
  426. float fraction = parent_time > SIMD_EPSILON ? (current_total_time / parent_time) * 100 : 0.f;
  427. {
  428. // LOL BEGIN
  429. int j; for (j=0;j<spacing;j++) printf(".");
  430. // LOL END
  431. }
  432. printf("%d -- %s (%.2f %%) :: %.3f ms / frame (%d calls)\n",i, profileIterator->Get_Current_Name(), fraction,(current_total_time / (double)frames_since_reset),profileIterator->Get_Current_Total_Calls());
  433. totalTime += current_total_time;
  434. //recurse into children
  435. }
  436. if (parent_time < accumulated_time)
  437. {
  438. printf("what's wrong\n");
  439. }
  440. for (i=0;i<spacing;i++) printf(".");
  441. printf("%s (%.3f %%) :: %.3f ms\n", "Unaccounted:",parent_time > SIMD_EPSILON ? ((parent_time - accumulated_time) / parent_time) * 100 : 0.f, parent_time - accumulated_time);
  442. for (i=0;i<numChildren;i++)
  443. {
  444. profileIterator->Enter_Child(i);
  445. dumpRecursive(profileIterator,spacing+3);
  446. profileIterator->Enter_Parent();
  447. }
  448. }
  449. void CProfileManager::dumpAll()
  450. {
  451. CProfileIterator* profileIterator = 0;
  452. profileIterator = CProfileManager::Get_Iterator();
  453. dumpRecursive(profileIterator,0);
  454. CProfileManager::Release_Iterator(profileIterator);
  455. }
  456. #endif //BT_NO_PROFILE