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