[1963] | 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; |
---|
[2430] | 113 | |
---|
[1963] | 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 | { |
---|
[2430] | 254 | gProfileClock.reset(); |
---|
[1963] | 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 | |
---|
[2430] | 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 | |
---|
[1963] | 345 | #endif //USE_BT_CLOCK |
---|
| 346 | |
---|