| 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 "LinearMath/btQuickprof.h" | 
|---|
| 17 |  | 
|---|
| 18 |  | 
|---|
| 19 | #ifdef USE_BT_CLOCK | 
|---|
| 20 |  | 
|---|
| 21 | static btClock gProfileClock; | 
|---|
| 22 |  | 
|---|
| 23 | inline void Profile_Get_Ticks(unsigned long int * ticks) | 
|---|
| 24 | { | 
|---|
| 25 |         *ticks = gProfileClock.getTimeMicroseconds(); | 
|---|
| 26 | } | 
|---|
| 27 |  | 
|---|
| 28 | inline float Profile_Get_Tick_Rate(void) | 
|---|
| 29 | { | 
|---|
| 30 | //      return 1000000.f; | 
|---|
| 31 |         return 1000.f; | 
|---|
| 32 |  | 
|---|
| 33 | } | 
|---|
| 34 |  | 
|---|
| 35 |  | 
|---|
| 36 |  | 
|---|
| 37 | /*************************************************************************************************** | 
|---|
| 38 | ** | 
|---|
| 39 | ** CProfileNode | 
|---|
| 40 | ** | 
|---|
| 41 | ***************************************************************************************************/ | 
|---|
| 42 |  | 
|---|
| 43 | /*********************************************************************************************** | 
|---|
| 44 |  * INPUT:                                                                                      * | 
|---|
| 45 |  * name - pointer to a static string which is the name of this profile node                    * | 
|---|
| 46 |  * parent - parent pointer                                                                     * | 
|---|
| 47 |  *                                                                                             * | 
|---|
| 48 |  * WARNINGS:                                                                                   * | 
|---|
| 49 |  * The name is assumed to be a static pointer, only the pointer is stored and compared for     * | 
|---|
| 50 |  * efficiency reasons.                                                                         * | 
|---|
| 51 |  *=============================================================================================*/ | 
|---|
| 52 | CProfileNode::CProfileNode( const char * name, CProfileNode * parent ) : | 
|---|
| 53 |         Name( name ), | 
|---|
| 54 |         TotalCalls( 0 ), | 
|---|
| 55 |         TotalTime( 0 ), | 
|---|
| 56 |         StartTime( 0 ), | 
|---|
| 57 |         RecursionCounter( 0 ), | 
|---|
| 58 |         Parent( parent ), | 
|---|
| 59 |         Child( NULL ), | 
|---|
| 60 |         Sibling( NULL ) | 
|---|
| 61 | { | 
|---|
| 62 |         Reset(); | 
|---|
| 63 | } | 
|---|
| 64 |  | 
|---|
| 65 |  | 
|---|
| 66 | void    CProfileNode::CleanupMemory() | 
|---|
| 67 | { | 
|---|
| 68 |         delete ( Child); | 
|---|
| 69 |         Child = NULL; | 
|---|
| 70 |         delete ( Sibling); | 
|---|
| 71 |         Sibling = NULL; | 
|---|
| 72 | } | 
|---|
| 73 |  | 
|---|
| 74 | CProfileNode::~CProfileNode( void ) | 
|---|
| 75 | { | 
|---|
| 76 |         delete ( Child); | 
|---|
| 77 |         delete ( Sibling); | 
|---|
| 78 | } | 
|---|
| 79 |  | 
|---|
| 80 |  | 
|---|
| 81 | /*********************************************************************************************** | 
|---|
| 82 |  * INPUT:                                                                                      * | 
|---|
| 83 |  * name - static string pointer to the name of the node we are searching for                   * | 
|---|
| 84 |  *                                                                                             * | 
|---|
| 85 |  * WARNINGS:                                                                                   * | 
|---|
| 86 |  * All profile names are assumed to be static strings so this function uses pointer compares   * | 
|---|
| 87 |  * to find the named node.                                                                     * | 
|---|
| 88 |  *=============================================================================================*/ | 
|---|
| 89 | CProfileNode * CProfileNode::Get_Sub_Node( const char * name ) | 
|---|
| 90 | { | 
|---|
| 91 |         // Try to find this sub node | 
|---|
| 92 |         CProfileNode * child = Child; | 
|---|
| 93 |         while ( child ) { | 
|---|
| 94 |                 if ( child->Name == name ) { | 
|---|
| 95 |                         return child; | 
|---|
| 96 |                 } | 
|---|
| 97 |                 child = child->Sibling; | 
|---|
| 98 |         } | 
|---|
| 99 |  | 
|---|
| 100 |         // We didn't find it, so add it | 
|---|
| 101 |          | 
|---|
| 102 |         CProfileNode * node = new CProfileNode( name, this ); | 
|---|
| 103 |         node->Sibling = Child; | 
|---|
| 104 |         Child = node; | 
|---|
| 105 |         return node; | 
|---|
| 106 | } | 
|---|
| 107 |  | 
|---|
| 108 |  | 
|---|
| 109 | void    CProfileNode::Reset( void ) | 
|---|
| 110 | { | 
|---|
| 111 |         TotalCalls = 0; | 
|---|
| 112 |         TotalTime = 0.0f; | 
|---|
| 113 |          | 
|---|
| 114 |  | 
|---|
| 115 |         if ( Child ) { | 
|---|
| 116 |                 Child->Reset(); | 
|---|
| 117 |         } | 
|---|
| 118 |         if ( Sibling ) { | 
|---|
| 119 |                 Sibling->Reset(); | 
|---|
| 120 |         } | 
|---|
| 121 | } | 
|---|
| 122 |  | 
|---|
| 123 |  | 
|---|
| 124 | void    CProfileNode::Call( void ) | 
|---|
| 125 | { | 
|---|
| 126 |         TotalCalls++; | 
|---|
| 127 |         if (RecursionCounter++ == 0) { | 
|---|
| 128 |                 Profile_Get_Ticks(&StartTime); | 
|---|
| 129 |         } | 
|---|
| 130 | } | 
|---|
| 131 |  | 
|---|
| 132 |  | 
|---|
| 133 | bool    CProfileNode::Return( void ) | 
|---|
| 134 | { | 
|---|
| 135 |         if ( --RecursionCounter == 0 && TotalCalls != 0 ) {  | 
|---|
| 136 |                 unsigned long int time; | 
|---|
| 137 |                 Profile_Get_Ticks(&time); | 
|---|
| 138 |                 time-=StartTime; | 
|---|
| 139 |                 TotalTime += (float)time / Profile_Get_Tick_Rate(); | 
|---|
| 140 |         } | 
|---|
| 141 |         return ( RecursionCounter == 0 ); | 
|---|
| 142 | } | 
|---|
| 143 |  | 
|---|
| 144 |  | 
|---|
| 145 | /*************************************************************************************************** | 
|---|
| 146 | ** | 
|---|
| 147 | ** CProfileIterator | 
|---|
| 148 | ** | 
|---|
| 149 | ***************************************************************************************************/ | 
|---|
| 150 | CProfileIterator::CProfileIterator( CProfileNode * start ) | 
|---|
| 151 | { | 
|---|
| 152 |         CurrentParent = start; | 
|---|
| 153 |         CurrentChild = CurrentParent->Get_Child(); | 
|---|
| 154 | } | 
|---|
| 155 |  | 
|---|
| 156 |  | 
|---|
| 157 | void    CProfileIterator::First(void) | 
|---|
| 158 | { | 
|---|
| 159 |         CurrentChild = CurrentParent->Get_Child(); | 
|---|
| 160 | } | 
|---|
| 161 |  | 
|---|
| 162 |  | 
|---|
| 163 | void    CProfileIterator::Next(void) | 
|---|
| 164 | { | 
|---|
| 165 |         CurrentChild = CurrentChild->Get_Sibling(); | 
|---|
| 166 | } | 
|---|
| 167 |  | 
|---|
| 168 |  | 
|---|
| 169 | bool    CProfileIterator::Is_Done(void) | 
|---|
| 170 | { | 
|---|
| 171 |         return CurrentChild == NULL; | 
|---|
| 172 | } | 
|---|
| 173 |  | 
|---|
| 174 |  | 
|---|
| 175 | void    CProfileIterator::Enter_Child( int index ) | 
|---|
| 176 | { | 
|---|
| 177 |         CurrentChild = CurrentParent->Get_Child(); | 
|---|
| 178 |         while ( (CurrentChild != NULL) && (index != 0) ) { | 
|---|
| 179 |                 index--; | 
|---|
| 180 |                 CurrentChild = CurrentChild->Get_Sibling(); | 
|---|
| 181 |         } | 
|---|
| 182 |  | 
|---|
| 183 |         if ( CurrentChild != NULL ) { | 
|---|
| 184 |                 CurrentParent = CurrentChild; | 
|---|
| 185 |                 CurrentChild = CurrentParent->Get_Child(); | 
|---|
| 186 |         } | 
|---|
| 187 | } | 
|---|
| 188 |  | 
|---|
| 189 |  | 
|---|
| 190 | void    CProfileIterator::Enter_Parent( void ) | 
|---|
| 191 | { | 
|---|
| 192 |         if ( CurrentParent->Get_Parent() != NULL ) { | 
|---|
| 193 |                 CurrentParent = CurrentParent->Get_Parent(); | 
|---|
| 194 |         } | 
|---|
| 195 |         CurrentChild = CurrentParent->Get_Child(); | 
|---|
| 196 | } | 
|---|
| 197 |  | 
|---|
| 198 |  | 
|---|
| 199 | /*************************************************************************************************** | 
|---|
| 200 | ** | 
|---|
| 201 | ** CProfileManager | 
|---|
| 202 | ** | 
|---|
| 203 | ***************************************************************************************************/ | 
|---|
| 204 |  | 
|---|
| 205 | CProfileNode    CProfileManager::Root( "Root", NULL ); | 
|---|
| 206 | CProfileNode *  CProfileManager::CurrentNode = &CProfileManager::Root; | 
|---|
| 207 | int                             CProfileManager::FrameCounter = 0; | 
|---|
| 208 | unsigned long int                       CProfileManager::ResetTime = 0; | 
|---|
| 209 |  | 
|---|
| 210 |  | 
|---|
| 211 | /*********************************************************************************************** | 
|---|
| 212 |  * CProfileManager::Start_Profile -- Begin a named profile                                    * | 
|---|
| 213 |  *                                                                                             * | 
|---|
| 214 |  * Steps one level deeper into the tree, if a child already exists with the specified name     * | 
|---|
| 215 |  * then it accumulates the profiling; otherwise a new child node is added to the profile tree. * | 
|---|
| 216 |  *                                                                                             * | 
|---|
| 217 |  * INPUT:                                                                                      * | 
|---|
| 218 |  * name - name of this profiling record                                                        * | 
|---|
| 219 |  *                                                                                             * | 
|---|
| 220 |  * WARNINGS:                                                                                   * | 
|---|
| 221 |  * The string used is assumed to be a static string; pointer compares are used throughout      * | 
|---|
| 222 |  * the profiling code for efficiency.                                                          * | 
|---|
| 223 |  *=============================================================================================*/ | 
|---|
| 224 | void    CProfileManager::Start_Profile( const char * name ) | 
|---|
| 225 | { | 
|---|
| 226 |         if (name != CurrentNode->Get_Name()) { | 
|---|
| 227 |                 CurrentNode = CurrentNode->Get_Sub_Node( name ); | 
|---|
| 228 |         }  | 
|---|
| 229 |          | 
|---|
| 230 |         CurrentNode->Call(); | 
|---|
| 231 | } | 
|---|
| 232 |  | 
|---|
| 233 |  | 
|---|
| 234 | /*********************************************************************************************** | 
|---|
| 235 |  * CProfileManager::Stop_Profile -- Stop timing and record the results.                       * | 
|---|
| 236 |  *=============================================================================================*/ | 
|---|
| 237 | void    CProfileManager::Stop_Profile( void ) | 
|---|
| 238 | { | 
|---|
| 239 |         // Return will indicate whether we should back up to our parent (we may | 
|---|
| 240 |         // be profiling a recursive function) | 
|---|
| 241 |         if (CurrentNode->Return()) { | 
|---|
| 242 |                 CurrentNode = CurrentNode->Get_Parent(); | 
|---|
| 243 |         } | 
|---|
| 244 | } | 
|---|
| 245 |  | 
|---|
| 246 |  | 
|---|
| 247 | /*********************************************************************************************** | 
|---|
| 248 |  * CProfileManager::Reset -- Reset the contents of the profiling system                       * | 
|---|
| 249 |  *                                                                                             * | 
|---|
| 250 |  *    This resets everything except for the tree structure.  All of the timing data is reset.  * | 
|---|
| 251 |  *=============================================================================================*/ | 
|---|
| 252 | void    CProfileManager::Reset( void ) | 
|---|
| 253 | {  | 
|---|
| 254 |         gProfileClock.reset(); | 
|---|
| 255 |         Root.Reset(); | 
|---|
| 256 |     Root.Call(); | 
|---|
| 257 |         FrameCounter = 0; | 
|---|
| 258 |         Profile_Get_Ticks(&ResetTime); | 
|---|
| 259 | } | 
|---|
| 260 |  | 
|---|
| 261 |  | 
|---|
| 262 | /*********************************************************************************************** | 
|---|
| 263 |  * CProfileManager::Increment_Frame_Counter -- Increment the frame counter                    * | 
|---|
| 264 |  *=============================================================================================*/ | 
|---|
| 265 | void CProfileManager::Increment_Frame_Counter( void ) | 
|---|
| 266 | { | 
|---|
| 267 |         FrameCounter++; | 
|---|
| 268 | } | 
|---|
| 269 |  | 
|---|
| 270 |  | 
|---|
| 271 | /*********************************************************************************************** | 
|---|
| 272 |  * CProfileManager::Get_Time_Since_Reset -- returns the elapsed time since last reset         * | 
|---|
| 273 |  *=============================================================================================*/ | 
|---|
| 274 | float CProfileManager::Get_Time_Since_Reset( void ) | 
|---|
| 275 | { | 
|---|
| 276 |         unsigned long int time; | 
|---|
| 277 |         Profile_Get_Ticks(&time); | 
|---|
| 278 |         time -= ResetTime; | 
|---|
| 279 |         return (float)time / Profile_Get_Tick_Rate(); | 
|---|
| 280 | } | 
|---|
| 281 |  | 
|---|
| 282 | #include <stdio.h> | 
|---|
| 283 |  | 
|---|
| 284 | void    CProfileManager::dumpRecursive(CProfileIterator* profileIterator, int spacing) | 
|---|
| 285 | { | 
|---|
| 286 |         profileIterator->First(); | 
|---|
| 287 |         if (profileIterator->Is_Done()) | 
|---|
| 288 |                 return; | 
|---|
| 289 |  | 
|---|
| 290 |         float accumulated_time=0,parent_time = profileIterator->Is_Root() ? CProfileManager::Get_Time_Since_Reset() : profileIterator->Get_Current_Parent_Total_Time(); | 
|---|
| 291 |         int i; | 
|---|
| 292 |         int frames_since_reset = CProfileManager::Get_Frame_Count_Since_Reset(); | 
|---|
| 293 |         for (i=0;i<spacing;i++) printf("."); | 
|---|
| 294 |         printf("----------------------------------\n"); | 
|---|
| 295 |         for (i=0;i<spacing;i++) printf("."); | 
|---|
| 296 |         printf("Profiling: %s (total running time: %.3f ms) ---\n",     profileIterator->Get_Current_Parent_Name(), parent_time ); | 
|---|
| 297 |         float totalTime = 0.f; | 
|---|
| 298 |  | 
|---|
| 299 |          | 
|---|
| 300 |         int numChildren = 0; | 
|---|
| 301 |          | 
|---|
| 302 |         for (i = 0; !profileIterator->Is_Done(); i++,profileIterator->Next()) | 
|---|
| 303 |         { | 
|---|
| 304 |                 numChildren++; | 
|---|
| 305 |                 float current_total_time = profileIterator->Get_Current_Total_Time(); | 
|---|
| 306 |                 accumulated_time += current_total_time; | 
|---|
| 307 |                 float fraction = parent_time > SIMD_EPSILON ? (current_total_time / parent_time) * 100 : 0.f; | 
|---|
| 308 |                 { | 
|---|
| 309 |                         int i;  for (i=0;i<spacing;i++) printf("."); | 
|---|
| 310 |                 } | 
|---|
| 311 |                 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()); | 
|---|
| 312 |                 totalTime += current_total_time; | 
|---|
| 313 |                 //recurse into children | 
|---|
| 314 |         } | 
|---|
| 315 |  | 
|---|
| 316 |         if (parent_time < accumulated_time) | 
|---|
| 317 |         { | 
|---|
| 318 |                 printf("what's wrong\n"); | 
|---|
| 319 |         } | 
|---|
| 320 |         for (i=0;i<spacing;i++) printf("."); | 
|---|
| 321 |         printf("%s (%.3f %%) :: %.3f ms\n", "Unaccounted:",parent_time > SIMD_EPSILON ? ((parent_time - accumulated_time) / parent_time) * 100 : 0.f, parent_time - accumulated_time); | 
|---|
| 322 |          | 
|---|
| 323 |         for (i=0;i<numChildren;i++) | 
|---|
| 324 |         { | 
|---|
| 325 |                 profileIterator->Enter_Child(i); | 
|---|
| 326 |                 dumpRecursive(profileIterator,spacing+3); | 
|---|
| 327 |                 profileIterator->Enter_Parent(); | 
|---|
| 328 |         } | 
|---|
| 329 | } | 
|---|
| 330 |  | 
|---|
| 331 |  | 
|---|
| 332 |  | 
|---|
| 333 | void    CProfileManager::dumpAll() | 
|---|
| 334 | { | 
|---|
| 335 |         CProfileIterator* profileIterator = 0; | 
|---|
| 336 |         profileIterator = CProfileManager::Get_Iterator(); | 
|---|
| 337 |  | 
|---|
| 338 |         dumpRecursive(profileIterator,0); | 
|---|
| 339 |  | 
|---|
| 340 |         CProfileManager::Release_Iterator(profileIterator); | 
|---|
| 341 | } | 
|---|
| 342 |  | 
|---|
| 343 |  | 
|---|
| 344 |  | 
|---|
| 345 | #endif //USE_BT_CLOCK | 
|---|
| 346 |  | 
|---|